You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/11/14 17:13:25 UTC

[JENKINS] Lucene-Solr-5.x-MacOSX (64bit/jdk1.8.0) - Build # 1895 - Failure!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-5.x-MacOSX/1895/
Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseParallelGC (asserts: false)

4 tests failed.
REGRESSION:  org.apache.solr.cloud.ClusterStateUpdateTest.testCoreRegistration

Error Message:


Stack Trace:
org.apache.solr.common.cloud.ZooKeeperException: 
	at __randomizedtesting.SeedInfo.seed([7C05023DFF0558D9:C28E6492867F56EC]:0)
	at org.apache.solr.cloud.ZkController.init(ZkController.java:639)
	at org.apache.solr.cloud.ZkController.<init>(ZkController.java:358)
	at org.apache.solr.core.ZkContainer.initZooKeeper(ZkContainer.java:134)
	at org.apache.solr.core.ZkContainer.initZooKeeper(ZkContainer.java:64)
	at org.apache.solr.core.CoreContainer.load(CoreContainer.java:237)
	at org.apache.solr.cloud.ClusterStateUpdateTest.testCoreRegistration(ClusterStateUpdateTest.java:226)
	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:483)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	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:54)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
	at java.lang.Thread.run(Thread.java:745)
Caused by: org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /live_nodes
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
	at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1045)
	at org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:313)
	at org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:310)
	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:61)
	at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:310)
	at org.apache.solr.common.cloud.ZkCmdExecutor.ensureExists(ZkCmdExecutor.java:90)
	at org.apache.solr.common.cloud.ZkCmdExecutor.ensureExists(ZkCmdExecutor.java:84)
	at org.apache.solr.cloud.ZkController.init(ZkController.java:601)
	... 45 more


FAILED:  junit.framework.TestSuite.org.apache.solr.cloud.ClusterStateUpdateTest

Error Message:
ERROR: SolrZkClient opens=11 closes=10

Stack Trace:
java.lang.AssertionError: ERROR: SolrZkClient opens=11 closes=10
	at __randomizedtesting.SeedInfo.seed([7C05023DFF0558D9]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.SolrTestCaseJ4.endTrackingZkClients(SolrTestCaseJ4.java:455)
	at org.apache.solr.SolrTestCaseJ4.afterClass(SolrTestCaseJ4.java:188)
	at sun.reflect.GeneratedMethodAccessor30.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:483)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:790)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	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:54)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
	at java.lang.Thread.run(Thread.java:745)


FAILED:  junit.framework.TestSuite.org.apache.solr.cloud.ClusterStateUpdateTest

Error Message:
5 threads leaked from SUITE scope at org.apache.solr.cloud.ClusterStateUpdateTest:     1) Thread[id=11722, name=zkCallback-1555-thread-2, state=TIMED_WAITING, group=TGRP-ClusterStateUpdateTest]         at sun.misc.Unsafe.park(Native Method)         at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)         at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)         at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)         at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)         at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)         at java.lang.Thread.run(Thread.java:745)    2) Thread[id=11720, name=zkCallback-1555-thread-1, state=TIMED_WAITING, group=TGRP-ClusterStateUpdateTest]         at sun.misc.Unsafe.park(Native Method)         at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)         at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)         at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)         at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)         at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)         at java.lang.Thread.run(Thread.java:745)    3) Thread[id=11724, name=TEST-ClusterStateUpdateTest.testCoreRegistration-seed#[7C05023DFF0558D9]-EventThread, state=WAITING, group=TGRP-ClusterStateUpdateTest]         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:494)    4) Thread[id=11726, name=zkCallback-1555-thread-3, state=TIMED_WAITING, group=TGRP-ClusterStateUpdateTest]         at sun.misc.Unsafe.park(Native Method)         at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)         at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)         at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)         at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)         at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)         at java.lang.Thread.run(Thread.java:745)    5) Thread[id=11723, name=TEST-ClusterStateUpdateTest.testCoreRegistration-seed#[7C05023DFF0558D9]-SendThread(127.0.0.1:58547), state=TIMED_WAITING, group=TGRP-ClusterStateUpdateTest]         at java.lang.Thread.sleep(Native Method)         at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:994)

Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 5 threads leaked from SUITE scope at org.apache.solr.cloud.ClusterStateUpdateTest: 
   1) Thread[id=11722, name=zkCallback-1555-thread-2, state=TIMED_WAITING, group=TGRP-ClusterStateUpdateTest]
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
        at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
        at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
   2) Thread[id=11720, name=zkCallback-1555-thread-1, state=TIMED_WAITING, group=TGRP-ClusterStateUpdateTest]
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
        at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
        at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
   3) Thread[id=11724, name=TEST-ClusterStateUpdateTest.testCoreRegistration-seed#[7C05023DFF0558D9]-EventThread, state=WAITING, group=TGRP-ClusterStateUpdateTest]
        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:494)
   4) Thread[id=11726, name=zkCallback-1555-thread-3, state=TIMED_WAITING, group=TGRP-ClusterStateUpdateTest]
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
        at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
        at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
   5) Thread[id=11723, name=TEST-ClusterStateUpdateTest.testCoreRegistration-seed#[7C05023DFF0558D9]-SendThread(127.0.0.1:58547), state=TIMED_WAITING, group=TGRP-ClusterStateUpdateTest]
        at java.lang.Thread.sleep(Native Method)
        at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:994)
	at __randomizedtesting.SeedInfo.seed([7C05023DFF0558D9]:0)


FAILED:  junit.framework.TestSuite.org.apache.solr.cloud.ClusterStateUpdateTest

Error Message:
There are still zombie threads that couldn't be terminated:    1) Thread[id=11722, name=zkCallback-1555-thread-2, state=TIMED_WAITING, group=TGRP-ClusterStateUpdateTest]         at sun.misc.Unsafe.park(Native Method)         at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)         at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)         at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)         at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)         at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)         at java.lang.Thread.run(Thread.java:745)    2) Thread[id=11720, name=zkCallback-1555-thread-1, state=TIMED_WAITING, group=TGRP-ClusterStateUpdateTest]         at sun.misc.Unsafe.park(Native Method)         at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)         at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)         at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)         at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)         at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)         at java.lang.Thread.run(Thread.java:745)    3) Thread[id=11726, name=zkCallback-1555-thread-3, state=TIMED_WAITING, group=TGRP-ClusterStateUpdateTest]         at sun.misc.Unsafe.park(Native Method)         at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)         at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)         at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)         at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)         at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)         at java.lang.Thread.run(Thread.java:745)    4) Thread[id=11723, name=TEST-ClusterStateUpdateTest.testCoreRegistration-seed#[7C05023DFF0558D9]-SendThread(127.0.0.1:58547), state=TIMED_WAITING, group=TGRP-ClusterStateUpdateTest]         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:940)         at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1003)

Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
   1) Thread[id=11722, name=zkCallback-1555-thread-2, state=TIMED_WAITING, group=TGRP-ClusterStateUpdateTest]
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
        at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
        at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
   2) Thread[id=11720, name=zkCallback-1555-thread-1, state=TIMED_WAITING, group=TGRP-ClusterStateUpdateTest]
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
        at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
        at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
   3) Thread[id=11726, name=zkCallback-1555-thread-3, state=TIMED_WAITING, group=TGRP-ClusterStateUpdateTest]
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
        at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
        at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
   4) Thread[id=11723, name=TEST-ClusterStateUpdateTest.testCoreRegistration-seed#[7C05023DFF0558D9]-SendThread(127.0.0.1:58547), state=TIMED_WAITING, group=TGRP-ClusterStateUpdateTest]
        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:940)
        at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1003)
	at __randomizedtesting.SeedInfo.seed([7C05023DFF0558D9]:0)




Build Log:
[...truncated 11664 lines...]
   [junit4] Suite: org.apache.solr.cloud.ClusterStateUpdateTest
   [junit4]   2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ClusterStateUpdateTest-7C05023DFF0558D9-001/init-core-data-001
   [junit4]   2> 4298911 T11668 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false)
   [junit4]   2> 4298931 T11668 oas.SolrTestCaseJ4.setUp ###Starting testCoreRegistration
   [junit4]   2> 4298932 T11668 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 4298933 T11669 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 4299033 T11668 oasc.ZkTestServer.run start zk server on port:58547
   [junit4]   2> 4299034 T11668 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 4299037 T11668 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 4299047 T11675 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@63531a6f name:ZooKeeperConnection Watcher:127.0.0.1:58547 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 4299048 T11668 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 4299048 T11668 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 4299048 T11668 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 4299059 T11668 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 4299063 T11668 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 4299066 T11677 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3a55605 name:ZooKeeperConnection Watcher:127.0.0.1:58547/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 4299066 T11668 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 4299067 T11668 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 4299067 T11668 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 4299077 T11668 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 4299088 T11668 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 4299093 T11668 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 4299100 T11668 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 4299100 T11668 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 4299110 T11668 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 4299110 T11668 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 4299119 T11668 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 4299119 T11668 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 4299128 T11668 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 4299129 T11668 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 4299135 T11668 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 4299136 T11668 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 4299143 T11668 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 4299144 T11668 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 4299151 T11668 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 4299151 T11668 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 4299157 T11668 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 4299159 T11668 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 4299165 T11668 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 4299166 T11668 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 4299173 T11668 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 4299174 T11668 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 4299183 T11668 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 4299183 T11668 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 4299192 T11668 oasc.ClusterStateUpdateTest.setUp ####SETUP_START testCoreRegistration
   [junit4]   2> 4299195 T11668 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ClusterStateUpdateTest-7C05023DFF0558D9-001/tempDir-001/'
   [junit4]   2> 4299235 T11668 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ClusterStateUpdateTest-7C05023DFF0558D9-001/tempDir-001/solr.xml
   [junit4]   2> 4299250 T11668 oasc.CoreContainer.<init> New CoreContainer 226513723
   [junit4]   2> 4299251 T11668 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ClusterStateUpdateTest-7C05023DFF0558D9-001/tempDir-001/]
   [junit4]   2> 4299252 T11668 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 4299252 T11668 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 4299252 T11668 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 4299253 T11668 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 4299253 T11668 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000
   [junit4]   2> 4299253 T11668 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 4299253 T11668 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 4299254 T11668 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 4299254 T11668 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 4299254 T11668 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 4299255 T11668 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
   [junit4]   2> 4299255 T11668 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 4299255 T11668 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 4299255 T11668 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 4299256 T11668 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:58547/solr
   [junit4]   2> 4299256 T11668 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 4299256 T11668 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 4299258 T11668 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 4299261 T11679 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3b1fbe87 name:ZooKeeperConnection Watcher:127.0.0.1:58547 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 4299262 T11668 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 4299263 T11668 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 4299271 T11668 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 4299275 T11681 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@59e3bd43 name:ZooKeeperConnection Watcher:127.0.0.1:58547/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 4299276 T11668 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 4299282 T11668 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 4299296 T11668 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 4299309 T11668 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 4299320 T11668 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 4299331 T11668 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 4299341 T11668 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 4299347 T11668 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:1661_solr
   [junit4]   2> 4299349 T11668 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:1661_solr
   [junit4]   2> 4299358 T11668 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 4299363 T11668 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 4299369 T11668 oasc.Overseer.close Overseer (id=null) closing
   [junit4]   2> 4299374 T11668 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:1661_solr
   [junit4]   2> 4299374 T11668 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 4299381 T11668 oasc.Overseer.start Overseer (id=92797752578342915-127.0.0.1:1661_solr-n_0000000000) starting
   [junit4]   2> 4299394 T11668 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 4299427 T11668 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000
   [junit4]   2> 4299429 T11683 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 4299431 T11668 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 4299437 T11668 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 4299442 T11668 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 4299457 T11682 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 4299463 T11685 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 4299464 T11685 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 4299466 T11685 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 4299467 T11686 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 4299476 T11682 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "core_node_name":"127.0.0.1:1661_solr_collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:1661/solr",
   [junit4]   2> 	  "node_name":"127.0.0.1:1661_solr",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 4299477 T11682 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 4299486 T11686 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 4300469 T11685 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 4300471 T11685 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 4300471 T11685 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 4300476 T11685 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 4300476 T11685 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ClusterStateUpdateTest-7C05023DFF0558D9-001/tempDir-001/collection1/'
   [junit4]   2> 4300538 T11685 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0
   [junit4]   2> 4300565 T11685 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 4300571 T11685 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml
   [junit4]   2> 4300581 T11685 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 4300691 T11685 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 4300696 T11685 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 4300697 T11685 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 4300723 T11685 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 4300727 T11685 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 4300731 T11685 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 4300735 T11685 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 4300735 T11685 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 4300735 T11685 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 4300738 T11685 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 4300738 T11685 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 4300739 T11685 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 4300739 T11685 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 4300739 T11685 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ClusterStateUpdateTest-7C05023DFF0558D9-001/tempDir-001/collection1/, dataDir=/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ClusterStateUpdateTest-7C05023DFF0558D9-001/zkData-001/data1/
   [junit4]   2> 4300739 T11685 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6f07c786
   [junit4]   2> 4300740 T11685 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ClusterStateUpdateTest-7C05023DFF0558D9-001/zkData-001/data1
   [junit4]   2> 4300740 T11685 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ClusterStateUpdateTest-7C05023DFF0558D9-001/zkData-001/data1/index/
   [junit4]   2> 4300740 T11685 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ClusterStateUpdateTest-7C05023DFF0558D9-001/zkData-001/data1/index' doesn't exist. Creating new index...
   [junit4]   2> 4300742 T11685 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ClusterStateUpdateTest-7C05023DFF0558D9-001/zkData-001/data1/index
   [junit4]   2> 4300742 T11685 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=11, maxMergeAtOnceExplicit=35, maxMergedSegmentMB=33.5400390625, floorSegmentMB=1.2919921875, forceMergeDeletesPctAllowed=17.143948940043103, segmentsPerTier=48.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 4300743 T11685 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@7b464bb7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5757c530)),segFN=segments_1,generation=1}
   [junit4]   2> 4300743 T11685 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 4300744 T11685 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
   [junit4]   2> 4300748 T11685 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 4300748 T11685 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 4300749 T11685 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 4300750 T11685 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 4300750 T11685 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 4300750 T11685 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 4300751 T11685 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 4300751 T11685 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 4300752 T11685 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 4300753 T11685 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 4300753 T11685 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 4300753 T11685 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 4300755 T11685 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 4300755 T11685 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 4300756 T11685 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 4300756 T11685 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 4300756 T11685 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 4300757 T11685 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 4300758 T11685 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 4300759 T11685 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
   [junit4]   2> 4300759 T11685 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
   [junit4]   2> 4300760 T11685 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 4300760 T11685 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 4300760 T11685 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 4300761 T11685 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
   [junit4]   2> 4300761 T11685 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
   [junit4]   2> 4300761 T11685 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
   [junit4]   2> 4300761 T11685 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 4300762 T11685 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 4300762 T11685 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 4300762 T11685 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 4300763 T11685 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 4300764 T11685 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 4300764 T11685 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 4300764 T11685 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 4300765 T11685 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 4300765 T11685 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
   [junit4]   2> 4300766 T11685 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
   [junit4]   2> 4300774 T11685 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4300775 T11685 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4300776 T11685 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4300777 T11685 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4300777 T11685 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
   [junit4]   2> 4300780 T11685 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 4300780 T11685 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 4300781 T11685 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=25, maxMergeAtOnceExplicit=27, maxMergedSegmentMB=1.251953125, floorSegmentMB=1.052734375, forceMergeDeletesPctAllowed=2.463016031715557, segmentsPerTier=34.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6367917419721195
   [junit4]   2> 4300781 T11685 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@7b464bb7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5757c530)),segFN=segments_1,generation=1}
   [junit4]   2> 4300781 T11685 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 4300781 T11685 oass.SolrIndexSearcher.<init> Opening Searcher@730aa12[collection1] main
   [junit4]   2> 4300782 T11685 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 4300785 T11685 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 4300785 T11685 oasr.RestManager.init Initializing RestManager with initArgs: {storageIO=org.apache.solr.rest.ManagedResourceStorage$InMemoryStorageIO}
   [junit4]   2> 4300786 T11685 oasr.ManagedResourceStorage.load Reading _rest_managed.json using InMemoryStorage
   [junit4]   2> 4300786 T11685 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /rest/managed
   [junit4]   2> 4300786 T11685 oasr.ManagedResourceStorage$JsonStorage.store Saved JSON object to path _rest_managed.json using InMemoryStorage
   [junit4]   2> 4300786 T11685 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 4300786 T11685 oashc.SpellCheckComponent.inform Initializing spell checkers
   [junit4]   2> 4300795 T11685 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 4300834 T11687 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@730aa12[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 4300838 T11685 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 4300840 T11690 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:1661/solr collection:collection1 shard:shard1
   [junit4]   2> 4300841 T11668 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ClusterStateUpdateTest-7C05023DFF0558D9-001/tempDir-001/'
   [junit4]   2> 4300842 T11690 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 4300852 T11690 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 4300856 T11690 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 4300856 T11690 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 4300856 T11690 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:1661/solr/collection1/ shard1
   [junit4]   2> 4300857 T11690 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 4300858 T11686 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 4300863 T11668 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ClusterStateUpdateTest-7C05023DFF0558D9-001/tempDir-001/solr.xml
   [junit4]   2> 4300871 T11668 oasc.CoreContainer.<init> New CoreContainer 1497397051
   [junit4]   2> 4300872 T11668 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ClusterStateUpdateTest-7C05023DFF0558D9-001/tempDir-001/]
   [junit4]   2> 4300873 T11668 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 4300873 T11668 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 4300874 T11668 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 4300875 T11668 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 4300875 T11668 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000
   [junit4]   2> 4300876 T11668 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 4300876 T11668 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 4300877 T11668 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 4300877 T11668 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 4300877 T11668 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 4300878 T11668 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
   [junit4]   2> 4300878 T11668 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 4300878 T11668 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 4300879 T11668 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 4300879 T11668 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:58547/solr
   [junit4]   2> 4300879 T11668 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 4300880 T11668 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 4300881 T11668 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 4300883 T11692 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@352641a6 name:ZooKeeperConnection Watcher:127.0.0.1:58547 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 4300884 T11668 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 4300885 T11668 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 4300889 T11668 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 4300891 T11694 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c06eb55 name:ZooKeeperConnection Watcher:127.0.0.1:58547/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 4300892 T11668 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 4300892 T11686 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 4300895 T11686 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 4300909 T11668 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 4300927 T11690 oasc.ZkController.register We are http://127.0.0.1:1661/solr/collection1/ and leader is http://127.0.0.1:1661/solr/collection1/
   [junit4]   2> 4300927 T11690 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:1661/solr
   [junit4]   2> 4300928 T11690 oasc.ZkController.checkRecovery WARN Skipping recovery according to sys prop solrcloud.skip.autorecovery
   [junit4]   2> 4300928 T11690 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 4300928 T11690 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 4300930 T11686 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 4300947 T11682 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "core_node_name":"127.0.0.1:1661_solr_collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:1661/solr",
   [junit4]   2> 	  "node_name":"127.0.0.1:1661_solr",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 4301063 T11686 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 4301065 T11695 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 4301921 T11668 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:1662_solr
   [junit4]   2> 4301925 T11668 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:1662_solr
   [junit4]   2> 4301941 T11668 oasc.Overseer.close Overseer (id=null) closing
   [junit4]   2> 4301954 T11696 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 4301954 T11696 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 4301956 T11696 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 4301956 T11686 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 4301966 T11682 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "core_node_name":"127.0.0.1:1662_solr_collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:1662/solr",
   [junit4]   2> 	  "node_name":"127.0.0.1:1662_solr",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 4301966 T11682 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
   [junit4]   2> 4301967 T11682 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 4302081 T11686 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 4302081 T11695 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 4302957 T11696 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 4302959 T11696 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 4302961 T11696 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 4302968 T11696 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 4302968 T11696 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ClusterStateUpdateTest-7C05023DFF0558D9-001/tempDir-001/collection1/'
   [junit4]   2> 4303008 T11696 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0
   [junit4]   2> 4303049 T11696 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 4303052 T11696 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml
   [junit4]   2> 4303058 T11696 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 4303198 T11696 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 4303206 T11696 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 4303207 T11696 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 4303240 T11696 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 4303245 T11696 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 4303250 T11696 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 4303253 T11696 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 4303254 T11696 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 4303255 T11696 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 4303258 T11696 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 4303259 T11696 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 4303259 T11696 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 4303259 T11696 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 4303260 T11696 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ClusterStateUpdateTest-7C05023DFF0558D9-001/tempDir-001/collection1/, dataDir=/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ClusterStateUpdateTest-7C05023DFF0558D9-001/zkData-001/data2/
   [junit4]   2> 4303260 T11696 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6f07c786
   [junit4]   2> 4303261 T11696 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ClusterStateUpdateTest-7C05023DFF0558D9-001/zkData-001/data2
   [junit4]   2> 4303261 T11696 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ClusterStateUpdateTest-7C05023DFF0558D9-001/zkData-001/data2/index/
   [junit4]   2> 4303261 T11696 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ClusterStateUpdateTest-7C05023DFF0558D9-001/zkData-001/data2/index' doesn't exist. Creating new index...
   [junit4]   2> 4303262 T11696 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ClusterStateUpdateTest-7C05023DFF0558D9-001/zkData-001/data2/index
   [junit4]   2> 4303263 T11696 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=11, maxMergeAtOnceExplicit=35, maxMergedSegmentMB=33.5400390625, floorSegmentMB=1.2919921875, forceMergeDeletesPctAllowed=17.143948940043103, segmentsPerTier=48.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 4303263 T11696 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@4d51cf22 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@545597c1)),segFN=segments_1,generation=1}
   [junit4]   2> 4303263 T11696 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 4303264 T11696 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
   [junit4]   2> 4303267 T11696 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 4303268 T11696 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 4303269 T11696 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 4303269 T11696 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 4303269 T11696 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 4303270 T11696 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 4303270 T11696 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 4303271 T11696 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 4303272 T11696 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 4303272 T11696 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 4303272 T11696 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 4303272 T11696 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 4303273 T11696 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 4303273 T11696 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 4303274 T11696 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 4303274 T11696 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 4303274 T11696 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 4303275 T11696 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 4303276 T11696 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 4303276 T11696 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
   [junit4]   2> 4303277 T11696 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
   [junit4]   2> 4303277 T11696 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 4303278 T11696 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 4303279 T11696 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 4303279 T11696 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
   [junit4]   2> 4303279 T11696 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
   [junit4]   2> 4303280 T11696 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
   [junit4]   2> 4303280 T11696 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 4303280 T11696 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 4303280 T11696 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 4303281 T11696 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 4303281 T11696 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 4303282 T11696 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 4303283 T11696 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 4303283 T11696 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 4303284 T11696 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 4303284 T11696 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
   [junit4]   2> 4303285 T11696 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
   [junit4]   2> 4303286 T11696 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4303288 T11696 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4303289 T11696 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4303291 T11696 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4303291 T11696 oasc.SolrCore.initDeprecatedSupport WARN solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
   [junit4]   2> 4303294 T11696 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 4303295 T11696 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 4303295 T11696 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=25, maxMergeAtOnceExplicit=27, maxMergedSegmentMB=1.251953125, floorSegmentMB=1.052734375, forceMergeDeletesPctAllowed=2.463016031715557, segmentsPerTier=34.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6367917419721195
   [junit4]   2> 4303296 T11696 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@4d51cf22 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@545597c1)),segFN=segments_1,generation=1}
   [junit4]   2> 4303296 T11696 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 4303296 T11696 oass.SolrIndexSearcher.<init> Opening Searcher@65af285b[collection1] main
   [junit4]   2> 4303296 T11696 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 4303299 T11696 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 4303300 T11696 oasr.RestManager.init Initializing RestManager with initArgs: {storageIO=org.apache.solr.rest.ManagedResourceStorage$InMemoryStorageIO}
   [junit4]   2> 4303302 T11696 oasr.ManagedResourceStorage.load Reading _rest_managed.json using InMemoryStorage
   [junit4]   2> 4303303 T11696 oasr.ManagedResource.reloadFromStorage WARN No stored data found for /rest/managed
   [junit4]   2> 4303304 T11696 oasr.ManagedResourceStorage$JsonStorage.store Saved JSON object to path _rest_managed.json using InMemoryStorage
   [junit4]   2> 4303305 T11696 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 4303305 T11696 oashc.SpellCheckComponent.inform Initializing spell checkers
   [junit4]   2> 4303317 T11696 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 4303374 T11697 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@65af285b[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 4303375 T11696 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 4303377 T11700 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:1662/solr collection:collection1 shard:shard1
   [junit4]   2> 4303379 T11668 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ClusterStateUpdateTest-7C05023DFF0558D9-001/tempDir-001/'
   [junit4]   2> 4303385 T11700 oasc.ZkController.register We are http://127.0.0.1:1662/solr/collection1/ and leader is http://127.0.0.1:1661/solr/collection1/
   [junit4]   2> 4303385 T11700 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:1662/solr
   [junit4]   2> 4303386 T11700 oasc.ZkController.checkRecovery WARN Skipping recovery according to sys prop solrcloud.skip.autorecovery
   [junit4]   2> 4303386 T11700 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 4303386 T11700 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 4303393 T11686 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 4303399 T11682 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "core_node_name":"127.0.0.1:1662_solr_collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:1662/solr",
   [junit4]   2> 	  "node_name":"127.0.0.1:1662_solr",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 4303408 T11668 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ClusterStateUpdateTest-7C05023DFF0558D9-001/tempDir-001/solr.xml
   [junit4]   2> 4303418 T11668 oasc.CoreContainer.<init> New CoreContainer 1248854483
   [junit4]   2> 4303419 T11668 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ClusterStateUpdateTest-7C05023DFF0558D9-001/tempDir-001/]
   [junit4]   2> 4303420 T11668 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 4303420 T11668 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 4303421 T11668 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 4303421 T11668 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 4303421 T11668 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000
   [junit4]   2> 4303421 T11668 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 4303422 T11668 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 4303422 T11668 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 4303422 T11668 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 4303422 T11668 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 4303423 T11668 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
   [junit4]   2> 4303423 T11668 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 4303423 T11668 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 4303424 T11668 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 4303424 T11668 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:58547/solr
   [junit4]   2> 4303424 T11668 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 4303425 T11668 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 4303426 T11668 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 4303429 T11702 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@799c8a0d name:ZooKeeperConnection Watcher:127.0.0.1:58547 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 4303431 T11668 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 4303431 T11668 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 4303436 T11668 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 4303438 T11704 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@eada704 name:ZooKeeperConnection Watcher:127.0.0.1:58547/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 4303439 T11668 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 4303454 T11668 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 4303507 T11686 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 4303508 T11695 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 4303509 T11705 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 4304465 T11668 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:1663_solr
   [junit4]   2> 4304467 T11668 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:1663_solr
   [junit4]   2> 4304477 T11668 oasc.Overseer.close Overseer (id=null) closing
   [junit4]   2> 4304486 T11706 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 4304486 T11706 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 4304488 T11686 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 4304488 T11706 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 4304496 T11682 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "core_node_name":"127.0.0.1:1663_solr_collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:1663/solr",
   [junit4]   2> 	  "node_name":"127.0.0.1:1663_solr",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 4304496 T11682 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
   [junit4]   2> 4304496 T11682 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 4304609 T11686 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 4304609 T11705 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 4304611 T11695 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 4305490 T11706 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 4305493 T11706 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 4305493 T11706 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 4305497 T11706 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 4305497 T11706 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ClusterStateUpdateTest-7C05023DFF0558D9-001/tempDir-001/collection1/'
   [junit4]   2> 4305580 T11706 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0
   [junit4]   2> 4305615 T11706 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 4305621 T11706 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml
   [junit4]   2> 4305627 T11706 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 4305804 T11706 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 4305811 T11706 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 4305814 T11706 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 4305845 T11706 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 4305849 T11706 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 4305855 T11706 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 4305859 T11706 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 4305859 T11706 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 4305859 T11706 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 4305863 T11706 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 4305863 T11706 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 4305864 T11706 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 4305864 T11706 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 4305864 T11706 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ClusterStateUpdateTest-7C05023DFF0558D9-001/tempDir-001/collection1/, dataDir=/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ClusterStateUpdateTest-7C05023DFF0558D9-001/zkData-001/data3/
   [junit4]   2> 4305865 T11706 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6f07c786
   [junit4]   2> 4305866 T11706 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ClusterStateUpdateTest-7C05023DFF0558D9-001/zkData-001/data3
   [junit4]   2> 4305866 T11706 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ClusterStateUpdateTest-7C05023DFF0558D9-001/zkData-001/data3/index/
   [junit4]   2> 4305866 T11706 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ClusterStateUpdateTest-7C05023DFF0558D9-001/zkData-001/data3/index' doesn't exist. Creating new index...
   [junit4]   2> 4305867 T11706 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ClusterStateUpdateTest-7C05023DFF0558D9-001/zkData-001/data3/index
   [junit4]   2> 4305868 T11706 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=11, maxMergeAtOnceExplicit=35, maxMergedSegmentMB=33.5400390625, floorSegmentMB=1.2919921875, forceMergeDeletesPctAllowed=17.143948940043103, segmentsPerTier=48.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 4305870 T11706 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirectoryWrapper(RAMDirectory@76fd3d09 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@74f67673)),segFN=segments_1,generation=1}
   [junit4]   2> 4305871 T11706 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 4305871 T11706 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
   [junit4]   2> 4305877 T11706 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 4305878 T11706 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 4305879 T11706 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 4305879 T11706 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
   [junit4]   2> 4305879 T11706 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 4305880 T11706 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 4305880 T11706 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 4305881 T11706 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
   [junit4]   2> 4305882 T11706 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 4305886 T11706 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 4305886 T11706 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 4305886 T11706 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 4305887 T11706 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 4305888 T11706 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 4305888 T11706 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 4305888 T11706 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 4305889 T11706 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 4305889 T11706 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 4305890 T11706 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 4305891 T11706 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
   [junit4]   2> 4305892 T11706 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
   [junit4]   2> 4305893 T11706 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 4305893 T11706 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 4305896 T11706 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 4305896 T11706 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
   [junit4]   2> 4305896 T11706 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
   [junit4]   2> 4305897 T11706 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
   [junit4]   2> 4305897 T11706 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 4305898 T11706 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 4305899 T11706 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 4305899 T11706 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 4305900 T11706 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
   [junit4]   2> 4305900 T11706 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: o

[...truncated too long message...]

tionError: ERROR: SolrZkClient opens=11 closes=10
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([7C05023DFF0558D9]:0)
   [junit4]    > 	at org.apache.solr.SolrTestCaseJ4.endTrackingZkClients(SolrTestCaseJ4.java:455)
   [junit4]    > 	at org.apache.solr.SolrTestCaseJ4.afterClass(SolrTestCaseJ4.java:188)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:745)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: 5 threads leaked from SUITE scope at org.apache.solr.cloud.ClusterStateUpdateTest: 
   [junit4]    >    1) Thread[id=11722, name=zkCallback-1555-thread-2, state=TIMED_WAITING, group=TGRP-ClusterStateUpdateTest]
   [junit4]    >         at sun.misc.Unsafe.park(Native Method)
   [junit4]    >         at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
   [junit4]    >         at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
   [junit4]    >         at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
   [junit4]    >         at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   [junit4]    >         at java.lang.Thread.run(Thread.java:745)
   [junit4]    >    2) Thread[id=11720, name=zkCallback-1555-thread-1, state=TIMED_WAITING, group=TGRP-ClusterStateUpdateTest]
   [junit4]    >         at sun.misc.Unsafe.park(Native Method)
   [junit4]    >         at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
   [junit4]    >         at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
   [junit4]    >         at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
   [junit4]    >         at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   [junit4]    >         at java.lang.Thread.run(Thread.java:745)
   [junit4]    >    3) Thread[id=11724, name=TEST-ClusterStateUpdateTest.testCoreRegistration-seed#[7C05023DFF0558D9]-EventThread, state=WAITING, group=TGRP-ClusterStateUpdateTest]
   [junit4]    >         at sun.misc.Unsafe.park(Native Method)
   [junit4]    >         at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
   [junit4]    >         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
   [junit4]    >         at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
   [junit4]    >         at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:494)
   [junit4]    >    4) Thread[id=11726, name=zkCallback-1555-thread-3, state=TIMED_WAITING, group=TGRP-ClusterStateUpdateTest]
   [junit4]    >         at sun.misc.Unsafe.park(Native Method)
   [junit4]    >         at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
   [junit4]    >         at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
   [junit4]    >         at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
   [junit4]    >         at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   [junit4]    >         at java.lang.Thread.run(Thread.java:745)
   [junit4]    >    5) Thread[id=11723, name=TEST-ClusterStateUpdateTest.testCoreRegistration-seed#[7C05023DFF0558D9]-SendThread(127.0.0.1:58547), state=TIMED_WAITING, group=TGRP-ClusterStateUpdateTest]
   [junit4]    >         at java.lang.Thread.sleep(Native Method)
   [junit4]    >         at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:994)
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([7C05023DFF0558D9]:0)Throwable #3: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
   [junit4]    >    1) Thread[id=11722, name=zkCallback-1555-thread-2, state=TIMED_WAITING, group=TGRP-ClusterStateUpdateTest]
   [junit4]    >         at sun.misc.Unsafe.park(Native Method)
   [junit4]    >         at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
   [junit4]    >         at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
   [junit4]    >         at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
   [junit4]    >         at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   [junit4]    >         at java.lang.Thread.run(Thread.java:745)
   [junit4]    >    2) Thread[id=11720, name=zkCallback-1555-thread-1, state=TIMED_WAITING, group=TGRP-ClusterStateUpdateTest]
   [junit4]    >         at sun.misc.Unsafe.park(Native Method)
   [junit4]    >         at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
   [junit4]    >         at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
   [junit4]    >         at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
   [junit4]    >         at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   [junit4]    >         at java.lang.Thread.run(Thread.java:745)
   [junit4]    >    3) Thread[id=11726, name=zkCallback-1555-thread-3, state=TIMED_WAITING, group=TGRP-ClusterStateUpdateTest]
   [junit4]    >         at sun.misc.Unsafe.park(Native Method)
   [junit4]    >         at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
   [junit4]    >         at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
   [junit4]    >         at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
   [junit4]    >         at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
   [junit4]    >         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   [junit4]    >         at java.lang.Thread.run(Thread.java:745)
   [junit4]    >    4) Thread[id=11723, name=TEST-ClusterStateUpdateTest.testCoreRegistration-seed#[7C05023DFF0558D9]-SendThread(127.0.0.1:58547), state=TIMED_WAITING, group=TGRP-ClusterStateUpdateTest]
   [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:940)
   [junit4]    >         at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1003)
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([7C05023DFF0558D9]:0)
   [junit4] Completed in 40.57s, 1 test, 1 failure, 3 errors <<< FAILURES!

[...truncated 658 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/build.xml:525: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/build.xml:473: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/build.xml:61: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/extra-targets.xml:39: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/build.xml:189: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/solr/common-build.xml:508: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/lucene/common-build.xml:1359: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-5.x-MacOSX/lucene/common-build.xml:966: There were test failures: 444 suites, 1818 tests, 3 suite-level errors, 1 error, 802 ignored (20 assumptions)

Total time: 121 minutes 30 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseParallelGC (asserts: false)
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any