Build: https://builds.apache.org/job/Lucene-Solr-Tests-7.2/5/
4 tests failed. FAILED: org.apache.solr.handler.TestReplicationHandler.doTestIndexAndConfigReplication Error Message: Index: 0, Size: 0 Stack Trace: java.lang.IndexOutOfBoundsException: Index: 0, Size: 0 at __randomizedtesting.SeedInfo.seed([19C524887EEBEE6B:D8D7FDD5DEC5375]:0) at java.util.ArrayList.rangeCheck(ArrayList.java:657) at java.util.ArrayList.get(ArrayList.java:433) at org.apache.solr.handler.TestReplicationHandler.doTestIndexAndConfigReplication(TestReplicationHandler.java:561) 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:1737) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984) 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:943) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890) 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.client.solrj.io.stream.StreamExpressionTest.testExecutorStream Error Message: Stack Trace: java.lang.AssertionError at __randomizedtesting.SeedInfo.seed([1CC18AF23ABE7FE:230C995400C1CDEE]:0) at org.junit.Assert.fail(Assert.java:92) at org.junit.Assert.assertTrue(Assert.java:43) at org.junit.Assert.assertTrue(Assert.java:54) at org.apache.solr.client.solrj.io.stream.StreamExpressionTest.testExecutorStream(StreamExpressionTest.java:8443) 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:1737) at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:934) at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:970) at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:984) 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:943) at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:829) at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:879) at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:890) 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.client.solrj.io.stream.StreamExpressionTest Error Message: 13 threads leaked from SUITE scope at org.apache.solr.client.solrj.io.stream.StreamExpressionTest: 1) Thread[id=3069, name=zkConnectionManagerCallback-980-thread-1-EventThread, state=WAITING, group=TGRP-StreamExpressionTest] 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) 2) Thread[id=2247, name=Connection evictor, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] 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) 3) Thread[id=3062, name=zkCallback-979-thread-2, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] 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:1073) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 4) Thread[id=2250, name=zkConnectionManagerCallback-980-thread-1, state=WAITING, group=TGRP-StreamExpressionTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 5) Thread[id=3064, name=zkCallback-979-thread-4, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] 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:1073) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 6) Thread[id=3063, name=zkCallback-979-thread-3, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] 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:1073) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 7) Thread[id=3068, name=zkConnectionManagerCallback-980-thread-1-SendThread(127.0.0.1:43238), state=TIMED_WAITING, group=TGRP-StreamExpressionTest] at java.lang.Thread.sleep(Native Method) at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1051) 8) Thread[id=3067, name=zkCallback-979-thread-5, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] 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:1073) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 9) Thread[id=2260, name=Connection evictor, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] 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) 10) Thread[id=2261, name=Connection evictor, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] 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) 11) Thread[id=2253, name=Connection evictor, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] 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) 12) Thread[id=3061, name=zkCallback-979-thread-1, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] 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:1073) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 13) Thread[id=2254, name=Connection evictor, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] 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) Stack Trace: com.carrotsearch.randomizedtesting.ThreadLeakError: 13 threads leaked from SUITE scope at org.apache.solr.client.solrj.io.stream.StreamExpressionTest: 1) Thread[id=3069, name=zkConnectionManagerCallback-980-thread-1-EventThread, state=WAITING, group=TGRP-StreamExpressionTest] 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) 2) Thread[id=2247, name=Connection evictor, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] 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) 3) Thread[id=3062, name=zkCallback-979-thread-2, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] 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:1073) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 4) Thread[id=2250, name=zkConnectionManagerCallback-980-thread-1, state=WAITING, group=TGRP-StreamExpressionTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 5) Thread[id=3064, name=zkCallback-979-thread-4, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] 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:1073) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 6) Thread[id=3063, name=zkCallback-979-thread-3, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] 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:1073) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 7) Thread[id=3068, name=zkConnectionManagerCallback-980-thread-1-SendThread(127.0.0.1:43238), state=TIMED_WAITING, group=TGRP-StreamExpressionTest] at java.lang.Thread.sleep(Native Method) at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1051) 8) Thread[id=3067, name=zkCallback-979-thread-5, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] 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:1073) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 9) Thread[id=2260, name=Connection evictor, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] 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) 10) Thread[id=2261, name=Connection evictor, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] 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) 11) Thread[id=2253, name=Connection evictor, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] 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) 12) Thread[id=3061, name=zkCallback-979-thread-1, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] 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:1073) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 13) Thread[id=2254, name=Connection evictor, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] 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) at __randomizedtesting.SeedInfo.seed([1CC18AF23ABE7FE]:0) FAILED: junit.framework.TestSuite.org.apache.solr.client.solrj.io.stream.StreamExpressionTest Error Message: There are still zombie threads that couldn't be terminated: 1) Thread[id=3063, name=zkCallback-979-thread-3, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] 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:1073) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 2) Thread[id=3068, name=zkConnectionManagerCallback-980-thread-1-SendThread(127.0.0.1:43238), state=TIMED_WAITING, group=TGRP-StreamExpressionTest] 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) 3) Thread[id=3067, name=zkCallback-979-thread-5, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] 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:1073) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 4) Thread[id=3062, name=zkCallback-979-thread-2, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] 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:1073) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 5) Thread[id=3061, name=zkCallback-979-thread-1, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] 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:1073) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 6) Thread[id=2250, name=zkConnectionManagerCallback-980-thread-1, state=WAITING, group=TGRP-StreamExpressionTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 7) Thread[id=3064, name=zkCallback-979-thread-4, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] 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:1073) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) Stack Trace: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated: 1) Thread[id=3063, name=zkCallback-979-thread-3, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] 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:1073) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 2) Thread[id=3068, name=zkConnectionManagerCallback-980-thread-1-SendThread(127.0.0.1:43238), state=TIMED_WAITING, group=TGRP-StreamExpressionTest] 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) 3) Thread[id=3067, name=zkCallback-979-thread-5, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] 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:1073) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 4) Thread[id=3062, name=zkCallback-979-thread-2, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] 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:1073) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 5) Thread[id=3061, name=zkCallback-979-thread-1, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] 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:1073) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 6) Thread[id=2250, name=zkConnectionManagerCallback-980-thread-1, state=WAITING, group=TGRP-StreamExpressionTest] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) 7) Thread[id=3064, name=zkCallback-979-thread-4, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] 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:1073) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) at java.lang.Thread.run(Thread.java:748) at __randomizedtesting.SeedInfo.seed([1CC18AF23ABE7FE]:0) Build Log: [...truncated 12785 lines...] [junit4] Suite: org.apache.solr.handler.TestReplicationHandler [junit4] 2> Creating dataDir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/init-core-data-001 [junit4] 2> 4148722 WARN (SUITE-TestReplicationHandler-seed#[19C524887EEBEE6B]-worker) [ ] o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=123 numCloses=123 [junit4] 2> 4148722 INFO (SUITE-TestReplicationHandler-seed#[19C524887EEBEE6B]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields (NUMERIC_POINTS_SYSPROP=true) w/NUMERIC_DOCVALUES_SYSPROP=true [junit4] 2> 4148724 INFO (SUITE-TestReplicationHandler-seed#[19C524887EEBEE6B]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl=None) [junit4] 2> 4148724 INFO (SUITE-TestReplicationHandler-seed#[19C524887EEBEE6B]-worker) [ ] o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom [junit4] 2> 4148740 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.SolrTestCaseJ4 ###Starting doTestReplicateAfterCoreReload [junit4] 2> 4148740 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-001/collection1 [junit4] 2> 4148759 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.e.j.s.Server jetty-9.3.20.v20170531 [junit4] 2> 4148760 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@63627a3c{/solr,null,AVAILABLE} [junit4] 2> 4148761 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@74c69b4b{HTTP/1.1,[http/1.1]}{127.0.0.1:38313} [junit4] 2> 4148761 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.e.j.s.Server Started @4163926ms [junit4] 2> 4148761 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-001/collection1/data, hostContext=/solr, hostPort=38313} [junit4] 2> 4148831 ERROR (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 4148831 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.2.0 [junit4] 2> 4148831 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null [junit4] 2> 4148831 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 4148831 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-12-08T19:20:17.943Z [junit4] 2> 4148831 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-001/solr.xml [junit4] 2> 4148848 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored [junit4] 2> 4148848 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored [junit4] 2> 4148849 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@33b25f80, but no JMX reporters were configured - adding default JMX reporter. [junit4] 2> 4149435 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@33b25f80 [junit4] 2> 4149602 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@33b25f80 [junit4] 2> 4149602 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@33b25f80 [junit4] 2> 4149689 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-001/. [junit4] 2> 4149689 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1] [junit4] 2> 4149708 INFO (coreLoadExecutor-5630-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores [junit4] 2> 4149928 INFO (coreLoadExecutor-5630-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.2.0 [junit4] 2> 4149968 INFO (coreLoadExecutor-5630-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 4150003 INFO (coreLoadExecutor-5630-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id [junit4] 2> 4150003 INFO (coreLoadExecutor-5630-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-001/./collection1, trusted=true [junit4] 2> 4150003 INFO (coreLoadExecutor-5630-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.collection1' (registry 'solr.core.collection1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@33b25f80 [junit4] 2> 4150003 INFO (coreLoadExecutor-5630-thread-1) [ x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 4150003 INFO (coreLoadExecutor-5630-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-001/collection1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-001/./collection1/data/] [junit4] 2> 4150018 INFO (coreLoadExecutor-5630-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=860648402, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1] [junit4] 2> 4150332 INFO (coreLoadExecutor-5630-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 4150332 INFO (coreLoadExecutor-5630-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 4150333 INFO (coreLoadExecutor-5630-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=11, maxMergeAtOnceExplicit=41, maxMergedSegmentMB=73.8076171875, floorSegmentMB=1.498046875, forceMergeDeletesPctAllowed=21.86503782315353, segmentsPerTier=38.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.46182928557724245 [junit4] 2> 4150334 INFO (coreLoadExecutor-5630-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@74f10456[collection1] main] [junit4] 2> 4150334 INFO (coreLoadExecutor-5630-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-001/collection1/conf [junit4] 2> 4150347 INFO (coreLoadExecutor-5630-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Replication enabled for following config files: schema.xml,xslt/dummy.xsl [junit4] 2> 4150347 INFO (coreLoadExecutor-5630-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms. [junit4] 2> 4150348 INFO (searcherExecutor-5631-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@74f10456[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 4150871 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-002/collection1 [junit4] 2> 4150874 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.e.j.s.Server jetty-9.3.20.v20170531 [junit4] 2> 4150908 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@70947622{/solr,null,AVAILABLE} [junit4] 2> 4150908 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@3d7227be{HTTP/1.1,[http/1.1]}{127.0.0.1:38966} [junit4] 2> 4150908 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.e.j.s.Server Started @4166073ms [junit4] 2> 4150908 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-002/collection1/data, hostContext=/solr, hostPort=38966} [junit4] 2> 4150908 ERROR (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 4150908 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.2.0 [junit4] 2> 4150909 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null [junit4] 2> 4150909 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 4150909 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-12-08T19:20:20.021Z [junit4] 2> 4150909 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-002/solr.xml [junit4] 2> 4150970 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored [junit4] 2> 4150970 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored [junit4] 2> 4150971 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@33b25f80, but no JMX reporters were configured - adding default JMX reporter. [junit4] 2> 4151466 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@33b25f80 [junit4] 2> 4151592 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@33b25f80 [junit4] 2> 4151592 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@33b25f80 [junit4] 2> 4151594 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-002/. [junit4] 2> 4151594 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1] [junit4] 2> 4151663 INFO (coreLoadExecutor-5640-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores [junit4] 2> 4151849 INFO (coreLoadExecutor-5640-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.2.0 [junit4] 2> 4152274 INFO (coreLoadExecutor-5640-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 4152276 INFO (coreLoadExecutor-5640-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id [junit4] 2> 4152276 INFO (coreLoadExecutor-5640-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-002/./collection1, trusted=true [junit4] 2> 4152276 INFO (coreLoadExecutor-5640-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.collection1' (registry 'solr.core.collection1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@33b25f80 [junit4] 2> 4152276 INFO (coreLoadExecutor-5640-thread-1) [ x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 4152276 INFO (coreLoadExecutor-5640-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-002/collection1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-002/./collection1/data/] [junit4] 2> 4152295 INFO (coreLoadExecutor-5640-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=860648402, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1] [junit4] 2> 4152831 INFO (coreLoadExecutor-5640-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 4152831 INFO (coreLoadExecutor-5640-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 4152832 INFO (coreLoadExecutor-5640-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=11, maxMergeAtOnceExplicit=41, maxMergedSegmentMB=73.8076171875, floorSegmentMB=1.498046875, forceMergeDeletesPctAllowed=21.86503782315353, segmentsPerTier=38.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.46182928557724245 [junit4] 2> 4152832 INFO (coreLoadExecutor-5640-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@74f23ba6[collection1] main] [junit4] 2> 4152833 INFO (coreLoadExecutor-5640-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-002/collection1/conf [junit4] 2> 4152888 INFO (coreLoadExecutor-5640-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 1000ms [junit4] 2> 4152888 INFO (coreLoadExecutor-5640-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms. [junit4] 2> 4152889 INFO (searcherExecutor-5641-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@74f23ba6[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 4152999 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@3d7227be{HTTP/1.1,[http/1.1]}{127.0.0.1:0} [junit4] 2> 4153000 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1510710727 [junit4] 2> 4153031 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null [junit4] 2> 4153031 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@32145cd5: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@62ca9047 [junit4] 2> 4153051 INFO (qtp1702328389-15486) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0 [junit4] 2> 4153051 INFO (indexFetcher-5645-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 1 [junit4] 2> 4153051 INFO (indexFetcher-5645-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Master's version: 0 [junit4] 2> 4153051 INFO (indexFetcher-5645-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 1 [junit4] 2> 4153051 INFO (indexFetcher-5645-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Slave's version: 0 [junit4] 2> 4153051 INFO (indexFetcher-5645-thread-1) [ x:collection1] o.a.s.h.IndexFetcher New index in Master. Deleting mine... [junit4] 2> 4153090 INFO (indexFetcher-5645-thread-1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 4153091 INFO (indexFetcher-5645-thread-1) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@402aa702 commitCommandVersion:0 [junit4] 2> 4153105 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null [junit4] 2> 4153106 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@6d4db104: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@79bbbb72 [junit4] 2> 4153163 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null [junit4] 2> 4153163 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@573c3089: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@5191e84e [junit4] 2> 4153176 INFO (indexFetcher-5645-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@255bfd9c[collection1] main] [junit4] 2> 4153213 INFO (indexFetcher-5645-thread-1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 4153215 INFO (searcherExecutor-5641-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@255bfd9c[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 4153221 INFO (coreCloseExecutor-5646-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@1e5c6416 [junit4] 2> 4153221 INFO (coreCloseExecutor-5646-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=509371414 [junit4] 2> 4153221 INFO (coreCloseExecutor-5646-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@7b4cd066: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1 / com.codahale.metrics.MetricRegistry@6b651edf [junit4] 2> 4153332 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@70947622{/solr,null,UNAVAILABLE} [junit4] 2> 4153380 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@74c69b4b{HTTP/1.1,[http/1.1]}{127.0.0.1:0} [junit4] 2> 4153380 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1905543775 [junit4] 2> 4153381 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, tag=null [junit4] 2> 4153381 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@32d8572b: rootName = null, domain = solr.node, service url = null, agent id = null] for registry solr.node / com.codahale.metrics.MetricRegistry@21d4f8ec [junit4] 2> 4153382 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, tag=null [junit4] 2> 4153382 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@7062a038: rootName = null, domain = solr.jvm, service url = null, agent id = null] for registry solr.jvm / com.codahale.metrics.MetricRegistry@79bbbb72 [junit4] 2> 4153383 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, tag=null [junit4] 2> 4153383 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@23c3cf2a: rootName = null, domain = solr.jetty, service url = null, agent id = null] for registry solr.jetty / com.codahale.metrics.MetricRegistry@5191e84e [junit4] 2> 4153421 INFO (coreCloseExecutor-5648-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@62856834 [junit4] 2> 4153421 INFO (coreCloseExecutor-5648-thread-1) [ x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.core.collection1, tag=1652910132 [junit4] 2> 4153421 INFO (coreCloseExecutor-5648-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter Closing reporter [org.apache.solr.metrics.reporters.SolrJmxReporter@33e55cbd: rootName = null, domain = solr.core.collection1, service url = null, agent id = null] for registry solr.core.collection1 / com.codahale.metrics.MetricRegistry@5a0df00a [junit4] 2> 4153620 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@63627a3c{/solr,null,UNAVAILABLE} [junit4] 2> 4153622 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.e.j.s.Server jetty-9.3.20.v20170531 [junit4] 2> 4153673 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@2902c7fb{/solr,null,AVAILABLE} [junit4] 2> 4153673 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@6e1e80a5{HTTP/1.1,[http/1.1]}{127.0.0.1:33014} [junit4] 2> 4153674 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.e.j.s.Server Started @4168839ms [junit4] 2> 4153674 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-001/collection1/data, hostContext=/solr, hostPort=33014} [junit4] 2> 4153674 ERROR (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 4153674 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.2.0 [junit4] 2> 4153674 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null [junit4] 2> 4153674 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 4153674 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-12-08T19:20:22.786Z [junit4] 2> 4153675 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-001/solr.xml [junit4] 2> 4153733 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored [junit4] 2> 4153733 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored [junit4] 2> 4153747 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@33b25f80, but no JMX reporters were configured - adding default JMX reporter. [junit4] 2> 4154165 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@33b25f80 [junit4] 2> 4154295 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@33b25f80 [junit4] 2> 4154296 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@33b25f80 [junit4] 2> 4154298 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-001/. [junit4] 2> 4154298 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1] [junit4] 2> 4154331 INFO (coreLoadExecutor-5655-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores [junit4] 2> 4154491 INFO (coreLoadExecutor-5655-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.2.0 [junit4] 2> 4154550 INFO (coreLoadExecutor-5655-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 4154603 INFO (coreLoadExecutor-5655-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id [junit4] 2> 4154603 INFO (coreLoadExecutor-5655-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-001/./collection1, trusted=true [junit4] 2> 4154603 INFO (coreLoadExecutor-5655-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.collection1' (registry 'solr.core.collection1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@33b25f80 [junit4] 2> 4154603 INFO (coreLoadExecutor-5655-thread-1) [ x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 4154603 INFO (coreLoadExecutor-5655-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-001/collection1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-001/./collection1/data/] [junit4] 2> 4154713 INFO (coreLoadExecutor-5655-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=860648402, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1] [junit4] 2> 4155244 INFO (coreLoadExecutor-5655-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 4155244 INFO (coreLoadExecutor-5655-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 4155245 INFO (coreLoadExecutor-5655-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=11, maxMergeAtOnceExplicit=41, maxMergedSegmentMB=73.8076171875, floorSegmentMB=1.498046875, forceMergeDeletesPctAllowed=21.86503782315353, segmentsPerTier=38.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.46182928557724245 [junit4] 2> 4155245 INFO (coreLoadExecutor-5655-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@187f6591[collection1] main] [junit4] 2> 4155245 INFO (coreLoadExecutor-5655-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-001/collection1/conf [junit4] 2> 4155246 INFO (coreLoadExecutor-5655-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Replication enabled for following config files: schema.xml [junit4] 2> 4155260 INFO (coreLoadExecutor-5655-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms. [junit4] 2> 4155260 INFO (searcherExecutor-5656-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@187f6591[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 4155825 INFO (qtp230185742-15528) [ x:collection1] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX [junit4] 2> 4155825 INFO (qtp230185742-15528) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={wt=javabin&version=2}{deleteByQuery=*:*} 0 0 [junit4] 2> 4155844 INFO (qtp230185742-15529) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false} [junit4] 2> 4155844 INFO (qtp230185742-15529) [ x:collection1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@6f563555 commitCommandVersion:0 [junit4] 2> 4155845 INFO (qtp230185742-15529) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@20acccf4[collection1] main] [junit4] 2> 4155846 INFO (qtp230185742-15529) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush [junit4] 2> 4155865 INFO (searcherExecutor-5656-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@20acccf4[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 4155880 INFO (qtp230185742-15529) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=/solr path=/update params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 36 [junit4] 2> 4155881 INFO (qtp230185742-15530) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=*:*&sort=id+desc&wt=javabin&version=2} hits=0 status=0 QTime=0 [junit4] 2> 4155882 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 0 docs [junit4] 2> 4155883 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.e.j.s.Server jetty-9.3.20.v20170531 [junit4] 2> 4155998 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@4fe862c4{/solr,null,AVAILABLE} [junit4] 2> 4155999 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@6b0bf65f{HTTP/1.1,[http/1.1]}{127.0.0.1:33551} [junit4] 2> 4155999 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.e.j.s.Server Started @4171164ms [junit4] 2> 4155999 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-002/collection1/data, hostContext=/solr, hostPort=33551} [junit4] 2> 4155999 ERROR (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete. [junit4] 2> 4155999 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 7.2.0 [junit4] 2> 4155999 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in standalone mode on port null [junit4] 2> 4155999 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null [junit4] 2> 4155999 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-12-08T19:20:25.111Z [junit4] 2> 4156000 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.c.SolrXmlConfig Loading container configuration from /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-002/solr.xml [junit4] 2> 4156125 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverWorkLoopDelay is ignored [junit4] 2> 4156125 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.c.SolrXmlConfig Configuration parameter autoReplicaFailoverBadNodeExpiration is ignored [junit4] 2> 4156127 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.c.SolrXmlConfig MBean server found: com.sun.jmx.mbeanserver.JmxMBeanServer@33b25f80, but no JMX reporters were configured - adding default JMX reporter. [junit4] 2> 4156357 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@33b25f80 [junit4] 2> 4156503 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@33b25f80 [junit4] 2> 4156503 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@33b25f80 [junit4] 2> 4156506 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-002/. [junit4] 2> 4156506 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.c.CorePropertiesLocator Cores are: [collection1] [junit4] 2> 4156539 INFO (coreLoadExecutor-5665-thread-1) [ ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 4 transient cores [junit4] 2> 4156630 INFO (coreLoadExecutor-5665-thread-1) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.2.0 [junit4] 2> 4156689 INFO (coreLoadExecutor-5665-thread-1) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 4156740 INFO (coreLoadExecutor-5665-thread-1) [ x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id [junit4] 2> 4156740 INFO (coreLoadExecutor-5665-thread-1) [ x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-002/./collection1, trusted=true [junit4] 2> 4156740 INFO (coreLoadExecutor-5665-thread-1) [ x:collection1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.collection1' (registry 'solr.core.collection1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@33b25f80 [junit4] 2> 4156741 INFO (coreLoadExecutor-5665-thread-1) [ x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder [junit4] 2> 4156741 INFO (coreLoadExecutor-5665-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-002/collection1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-002/./collection1/data/] [junit4] 2> 4156742 INFO (coreLoadExecutor-5665-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=860648402, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1] [junit4] 2> 4157037 INFO (coreLoadExecutor-5665-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 4157037 INFO (coreLoadExecutor-5665-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 4157038 INFO (coreLoadExecutor-5665-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=11, maxMergeAtOnceExplicit=41, maxMergedSegmentMB=73.8076171875, floorSegmentMB=1.498046875, forceMergeDeletesPctAllowed=21.86503782315353, segmentsPerTier=38.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.46182928557724245 [junit4] 2> 4157038 INFO (coreLoadExecutor-5665-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@4c0203c7[collection1] main] [junit4] 2> 4157038 INFO (coreLoadExecutor-5665-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-002/collection1/conf [junit4] 2> 4157070 INFO (coreLoadExecutor-5665-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Poll scheduled at an interval of 1000ms [junit4] 2> 4157070 INFO (coreLoadExecutor-5665-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms. [junit4] 2> 4157071 INFO (searcherExecutor-5666-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@4c0203c7[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 4157162 INFO (qtp230185742-15532) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0 [junit4] 2> 4157162 INFO (qtp875009404-15546) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/select params={q=*:*&sort=id+desc&wt=javabin&version=2} hits=0 status=0 QTime=0 [junit4] 2> 4157162 INFO (TEST-TestReplicationHandler.doTestReplicateAfterCoreReload-seed#[19C524887EEBEE6B]) [ ] o.a.s.h.TestReplicationHandler Waited for 0ms and found 0 docs [junit4] 2> 4157163 INFO (qtp230185742-15530) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getIndexVersion&qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0 [junit4] 2> 4157163 INFO (qtp230185742-15530) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={_trace=getCommits&qt=/replication&wt=javabin&version=2&command=commits} status=0 QTime=0 [junit4] 2> 4157166 INFO (indexFetcher-5670-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 2 [junit4] 2> 4157166 INFO (indexFetcher-5670-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Master's version: 1512760824956 [junit4] 2> 4157166 INFO (indexFetcher-5670-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 1 [junit4] 2> 4157166 INFO (indexFetcher-5670-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Slave's version: 0 [junit4] 2> 4157166 INFO (indexFetcher-5670-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Starting replication process [junit4] 2> 4157168 INFO (qtp230185742-15532) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&tlogFiles=false&wt=javabin&version=2&command=filelist} status=0 QTime=1 [junit4] 2> 4157168 INFO (indexFetcher-5670-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Number of files in latest index in master: 1 [junit4] 2> 4157236 INFO (indexFetcher-5670-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=43, maxMergeAtOnceExplicit=49, maxMergedSegmentMB=44.3603515625, floorSegmentMB=2.072265625, forceMergeDeletesPctAllowed=14.529284318883912, segmentsPerTier=13.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8137746919981468 [junit4] 2> 4157236 INFO (indexFetcher-5670-thread-1) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used. [junit4] 2> 4157237 INFO (indexFetcher-5670-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Starting download (fullCopy=false) to MockDirectoryWrapper(RAMDirectory@c247f3a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@753cb47f) [junit4] 2> 4157237 INFO (qtp230185742-15526) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={generation=2&qt=/replication&file=segments_2&checksum=true&wt=filestream&command=filecontent} status=0 QTime=0 [junit4] 2> 4157255 INFO (indexFetcher-5670-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Total time taken for download (fullCopy=false,bytesDownloaded=117) : 0 secs (null bytes/sec) to MockDirectoryWrapper(RAMDirectory@c247f3a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@753cb47f) [junit4] 2> 4157256 INFO (indexFetcher-5670-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=24, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.27442573062915054] [junit4] 2> 4157404 INFO (indexFetcher-5670-thread-1) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used. [junit4] 2> 4157405 INFO (qtp230185742-15531) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.2.0 [junit4] 2> 4157419 INFO (indexFetcher-5670-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@55500aea[collection1] main] [junit4] 2> 4157423 INFO (searcherExecutor-5666-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@55500aea[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 4157493 INFO (qtp230185742-15531) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test [junit4] 2> 4157511 INFO (qtp230185742-15531) [ ] o.a.s.s.IndexSchema Loaded schema test/1.2 with uniqueid field id [junit4] 2> 4157511 INFO (qtp230185742-15531) [ ] o.a.s.c.CoreContainer Reloading SolrCore 'collection1' using configuration from instancedir /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-001/./collection1 [junit4] 2> 4157676 INFO (qtp230185742-15531) [ x:collection1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.collection1' (registry 'solr.core.collection1') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@33b25f80 [junit4] 2> 4157676 INFO (qtp230185742-15531) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-001/collection1], dataDir=[/home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-001/./collection1/data/] [junit4] 2> 4158065 INFO (qtp230185742-15525) [ x:collection1] o.a.s.c.S.Request [collection1] webapp=/solr path=/replication params={qt=/replication&wt=javabin&version=2&command=indexversion} status=0 QTime=0 [junit4] 2> 4158065 INFO (indexFetcher-5670-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Master's generation: 2 [junit4] 2> 4158065 INFO (indexFetcher-5670-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Master's version: 1512760824956 [junit4] 2> 4158065 INFO (indexFetcher-5670-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Slave's generation: 2 [junit4] 2> 4158065 INFO (indexFetcher-5670-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Slave's version: 1512760824956 [junit4] 2> 4158065 INFO (indexFetcher-5670-thread-1) [ x:collection1] o.a.s.h.IndexFetcher Slave in sync with master. [junit4] 2> 4158170 INFO (qtp230185742-15531) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled [junit4] 2> 4158170 INFO (qtp230185742-15531) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled [junit4] 2> 4158172 INFO (qtp230185742-15531) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening [Searcher@121bac2c[collection1] main] [junit4] 2> 4158172 INFO (qtp230185742-15531) [ x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: /home/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.2/solr/build/solr-core/test/J2/temp/solr.handler.TestReplicationHandler_19C524887EEBEE6B-001/solr-instance-001/collection1/conf [junit4] 2> 4158173 INFO (qtp230185742-15531) [ x:collection1] o.a.s.h.ReplicationHandler Replication enabled for following config files: schema.xml [junit4] 2> 4158173 INFO (qtp230185742-15531) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms. [junit4] 2> 4158213 INFO (searcherExecutor-5672-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@121bac2c[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())} [junit4] 2> 4158214 INFO (qtp230185742-15531) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=667897824, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1] [junit4] 2> 4158214 INFO (qtp2301 [...truncated too long message...] [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:1073) [junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) [junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] > 9) Thread[id=2260, name=Connection evictor, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] [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] > 10) Thread[id=2261, name=Connection evictor, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] [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] > 11) Thread[id=2253, name=Connection evictor, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] [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] > 12) Thread[id=3061, name=zkCallback-979-thread-1, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] [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:1073) [junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) [junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] > 13) Thread[id=2254, name=Connection evictor, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] [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] > at __randomizedtesting.SeedInfo.seed([1CC18AF23ABE7FE]:0)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated: [junit4] > 1) Thread[id=3063, name=zkCallback-979-thread-3, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] [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:1073) [junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) [junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] > 2) Thread[id=3068, name=zkConnectionManagerCallback-980-thread-1-SendThread(127.0.0.1:43238), state=TIMED_WAITING, group=TGRP-StreamExpressionTest] [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] > 3) Thread[id=3067, name=zkCallback-979-thread-5, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] [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:1073) [junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) [junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] > 4) Thread[id=3062, name=zkCallback-979-thread-2, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] [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:1073) [junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) [junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] > 5) Thread[id=3061, name=zkCallback-979-thread-1, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] [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:1073) [junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) [junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] > 6) Thread[id=2250, name=zkConnectionManagerCallback-980-thread-1, state=WAITING, group=TGRP-StreamExpressionTest] [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 java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1074) [junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) [junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] > 7) Thread[id=3064, name=zkCallback-979-thread-4, state=TIMED_WAITING, group=TGRP-StreamExpressionTest] [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:1073) [junit4] > at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1134) [junit4] > at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [junit4] > at java.lang.Thread.run(Thread.java:748) [junit4] > at __randomizedtesting.SeedInfo.seed([1CC18AF23ABE7FE]:0) [junit4] Completed [114/146 (1!)] on J0 in 533.86s, 139 tests, 1 failure, 2 errors, 9 skipped <<< FAILURES! [...truncated 46517 lines...]
--------------------------------------------------------------------- To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org For additional commands, e-mail: dev-h...@lucene.apache.org