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/05/21 12:55:06 UTC

[JENKINS] Lucene-Solr-trunk-MacOSX (64bit/jdk1.7.0) - Build # 1590 - Failure!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-MacOSX/1590/
Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseSerialGC

4 tests failed.
REGRESSION:  org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testDistribSearch

Error Message:
some core start times did not change on reload

Stack Trace:
java.lang.AssertionError: some core start times did not change on reload
	at __randomizedtesting.SeedInfo.seed([3708010A5BE56C52:B6EE8F122CBA0C6E]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.assertTrue(Assert.java:43)
	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:836)
	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:203)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:863)
	at sun.reflect.GeneratedMethodAccessor37.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	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:360)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
	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:43)
	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:360)
	at java.lang.Thread.run(Thread.java:745)


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

Error Message:
ERROR: SolrZkClient opens=18 closes=17

Stack Trace:
java.lang.AssertionError: ERROR: SolrZkClient opens=18 closes=17
	at __randomizedtesting.SeedInfo.seed([3708010A5BE56C52]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.SolrTestCaseJ4.endTrackingZkClients(SolrTestCaseJ4.java:451)
	at org.apache.solr.SolrTestCaseJ4.afterClass(SolrTestCaseJ4.java:185)
	at sun.reflect.GeneratedMethodAccessor29.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	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:43)
	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:360)
	at java.lang.Thread.run(Thread.java:745)


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

Error Message:
2 threads leaked from SUITE scope at org.apache.solr.cloud.CollectionsAPIDistributedZkTest:     1) Thread[id=7822, name=TEST-CollectionsAPIDistributedZkTest.testDistribSearch-seed#[3708010A5BE56C52]-EventThread, state=WAITING, group=TGRP-CollectionsAPIDistributedZkTest]         at sun.misc.Unsafe.park(Native Method)         at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)         at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)         at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:494)    2) Thread[id=7821, name=TEST-CollectionsAPIDistributedZkTest.testDistribSearch-seed#[3708010A5BE56C52]-SendThread(127.0.0.1:51970), state=TIMED_WAITING, group=TGRP-CollectionsAPIDistributedZkTest]         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: 2 threads leaked from SUITE scope at org.apache.solr.cloud.CollectionsAPIDistributedZkTest: 
   1) Thread[id=7822, name=TEST-CollectionsAPIDistributedZkTest.testDistribSearch-seed#[3708010A5BE56C52]-EventThread, state=WAITING, group=TGRP-CollectionsAPIDistributedZkTest]
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
        at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:494)
   2) Thread[id=7821, name=TEST-CollectionsAPIDistributedZkTest.testDistribSearch-seed#[3708010A5BE56C52]-SendThread(127.0.0.1:51970), state=TIMED_WAITING, group=TGRP-CollectionsAPIDistributedZkTest]
        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([3708010A5BE56C52]:0)


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

Error Message:
There are still zombie threads that couldn't be terminated:    1) Thread[id=7821, name=TEST-CollectionsAPIDistributedZkTest.testDistribSearch-seed#[3708010A5BE56C52]-SendThread(127.0.0.1:51970), state=TIMED_WAITING, group=TGRP-CollectionsAPIDistributedZkTest]         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=7821, name=TEST-CollectionsAPIDistributedZkTest.testDistribSearch-seed#[3708010A5BE56C52]-SendThread(127.0.0.1:51970), state=TIMED_WAITING, group=TGRP-CollectionsAPIDistributedZkTest]
        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([3708010A5BE56C52]:0)




Build Log:
[...truncated 11221 lines...]
   [junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
   [junit4]   2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/init-core-data-001
   [junit4]   2> 2588556 T7666 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false)
   [junit4]   2> 2588556 T7666 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 2588564 T7666 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> 2588566 T7666 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 2588567 T7667 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 2588670 T7666 oasc.ZkTestServer.run start zk server on port:51970
   [junit4]   2> 2588671 T7666 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2588679 T7673 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c393e3f name:ZooKeeperConnection Watcher:127.0.0.1:51970 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2588680 T7666 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2588680 T7666 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 2588691 T7666 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2588698 T7675 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c907dc name:ZooKeeperConnection Watcher:127.0.0.1:51970/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2588698 T7666 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2588699 T7666 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 2588708 T7666 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 2588716 T7666 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 2588723 T7666 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 2588733 T7666 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 2588734 T7666 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 2588745 T7666 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 2588746 T7666 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 2588755 T7666 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 2588756 T7666 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 2588765 T7666 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 2588766 T7666 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 2588775 T7666 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 2588776 T7666 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 2588785 T7666 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 2588785 T7666 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 2588795 T7666 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 2588795 T7666 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 2588803 T7666 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 2588804 T7666 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 2588812 T7666 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 2588813 T7666 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 2588821 T7666 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 2588821 T7666 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 2588830 T7666 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 2588830 T7666 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> Using old style solr.xml
   [junit4]   2> 2590306 T7666 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 2590314 T7666 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51973
   [junit4]   2> 2590315 T7666 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 2590315 T7666 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 2590315 T7666 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-002
   [junit4]   2> 2590316 T7666 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-002/'
   [junit4]   2> 2590353 T7666 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-002/solr.xml
   [junit4]   2> 2590448 T7666 oasc.CoreContainer.<init> New CoreContainer 1901481855
   [junit4]   2> 2590448 T7666 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-002/]
   [junit4]   2> 2590450 T7666 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 2590450 T7666 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
   [junit4]   2> 2590451 T7666 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 2590451 T7666 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 2590452 T7666 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 2590452 T7666 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 2590453 T7666 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 2590453 T7666 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 2590454 T7666 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 2590455 T7666 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 2590455 T7666 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 2590455 T7666 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 2590456 T7666 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51970/solr
   [junit4]   2> 2590456 T7666 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 2590458 T7666 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2590462 T7686 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@597d54fa name:ZooKeeperConnection Watcher:127.0.0.1:51970 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2590462 T7666 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2590468 T7666 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2590471 T7688 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@507f5d80 name:ZooKeeperConnection Watcher:127.0.0.1:51970/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2590472 T7666 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2590477 T7666 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 2590486 T7666 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 2590494 T7666 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 2590503 T7666 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 2590511 T7666 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 2590520 T7666 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 2590525 T7666 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51973_
   [junit4]   2> 2590527 T7666 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51973_
   [junit4]   2> 2590535 T7666 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 2590545 T7666 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 2590557 T7666 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:51973_
   [junit4]   2> 2590557 T7666 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 2590563 T7666 oasc.Overseer.start Overseer (id=91794272975978499-127.0.0.1:51973_-n_0000000000) starting
   [junit4]   2> 2590575 T7666 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 2590604 T7690 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 2590605 T7666 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 2590613 T7666 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 2590617 T7666 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2590627 T7689 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 2590972 T7666 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 2590973 T7666 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 2590975 T7666 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2590980 T7693 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1dd59f41 name:ZooKeeperConnection Watcher:127.0.0.1:51970/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2590981 T7666 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2590986 T7666 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2590993 T7666 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 2592482 T7666 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
   [junit4]   2> 2592484 T7666 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 2592488 T7666 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51977
   [junit4]   2> 2592489 T7666 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 2592489 T7666 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 2592490 T7666 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-003
   [junit4]   2> 2592491 T7666 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-003/'
   [junit4]   2> 2592533 T7666 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-003/solr.xml
   [junit4]   2> 2592662 T7666 oasc.CoreContainer.<init> New CoreContainer 355521690
   [junit4]   2> 2592663 T7666 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-003/]
   [junit4]   2> 2592665 T7666 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 2592665 T7666 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
   [junit4]   2> 2592665 T7666 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 2592665 T7666 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 2592666 T7666 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 2592666 T7666 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 2592667 T7666 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 2592667 T7666 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 2592667 T7666 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 2592668 T7666 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 2592668 T7666 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 2592669 T7666 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 2592669 T7666 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51970/solr
   [junit4]   2> 2592670 T7666 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 2592672 T7666 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2592677 T7704 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@38d5d554 name:ZooKeeperConnection Watcher:127.0.0.1:51970 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2592677 T7666 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2592682 T7666 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2592687 T7706 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7f78e73f name:ZooKeeperConnection Watcher:127.0.0.1:51970/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2592687 T7666 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2592709 T7666 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2593720 T7666 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51977_
   [junit4]   2> 2593723 T7666 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51977_
   [junit4]   2> 2593746 T7666 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 2593747 T7666 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 2595284 T7666 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
   [junit4]   2> 2595285 T7666 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 2595289 T7666 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51980
   [junit4]   2> 2595291 T7666 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 2595293 T7666 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 2595293 T7666 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-004
   [junit4]   2> 2595293 T7666 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-004/'
   [junit4]   2> 2595346 T7666 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-004/solr.xml
   [junit4]   2> 2595453 T7666 oasc.CoreContainer.<init> New CoreContainer 1427853235
   [junit4]   2> 2595453 T7666 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-004/]
   [junit4]   2> 2595455 T7666 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 2595456 T7666 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
   [junit4]   2> 2595456 T7666 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 2595457 T7666 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 2595457 T7666 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 2595458 T7666 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 2595458 T7666 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 2595458 T7666 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 2595459 T7666 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 2595459 T7666 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 2595459 T7666 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 2595460 T7666 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 2595460 T7666 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51970/solr
   [junit4]   2> 2595461 T7666 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 2595462 T7666 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2595467 T7718 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@740d9c6b name:ZooKeeperConnection Watcher:127.0.0.1:51970 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2595468 T7666 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2595476 T7666 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2595480 T7720 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19ae36ca name:ZooKeeperConnection Watcher:127.0.0.1:51970/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2595481 T7666 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2595507 T7666 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2596518 T7666 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51980_
   [junit4]   2> 2596521 T7666 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51980_
   [junit4]   2> 2596558 T7666 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 2596558 T7666 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 2598525 T7666 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
   [junit4]   2> 2598526 T7666 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 2598534 T7666 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51983
   [junit4]   2> 2598536 T7666 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 2598537 T7666 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 2598537 T7666 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-005
   [junit4]   2> 2598539 T7666 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-005/'
   [junit4]   2> 2598602 T7666 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-005/solr.xml
   [junit4]   2> 2598784 T7666 oasc.CoreContainer.<init> New CoreContainer 1371663259
   [junit4]   2> 2598785 T7666 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-005/]
   [junit4]   2> 2598788 T7666 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 2598788 T7666 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
   [junit4]   2> 2598789 T7666 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 2598789 T7666 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 2598790 T7666 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 2598790 T7666 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 2598790 T7666 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 2598791 T7666 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 2598791 T7666 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 2598792 T7666 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 2598793 T7666 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 2598794 T7666 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 2598794 T7666 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51970/solr
   [junit4]   2> 2598795 T7666 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 2598797 T7666 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2598803 T7732 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1253370c name:ZooKeeperConnection Watcher:127.0.0.1:51970 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2598804 T7666 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2598812 T7666 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2598816 T7734 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@67b955de name:ZooKeeperConnection Watcher:127.0.0.1:51970/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2598817 T7666 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2598844 T7666 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2599857 T7666 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51983_
   [junit4]   2> 2599860 T7666 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51983_
   [junit4]   2> 2599888 T7666 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 2599888 T7666 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 2601352 T7666 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 4
   [junit4]   2> 2601353 T7666 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 2601360 T7666 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51986
   [junit4]   2> 2601362 T7666 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 2601363 T7666 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 2601363 T7666 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-006
   [junit4]   2> 2601364 T7666 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-006/'
   [junit4]   2> 2601411 T7666 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-006/solr.xml
   [junit4]   2> 2601518 T7666 oasc.CoreContainer.<init> New CoreContainer 1448844589
   [junit4]   2> 2601519 T7666 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-006/]
   [junit4]   2> 2601521 T7666 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 2601522 T7666 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
   [junit4]   2> 2601522 T7666 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 2601522 T7666 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 2601523 T7666 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 2601523 T7666 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 2601523 T7666 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 2601524 T7666 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 2601524 T7666 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 2601525 T7666 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 2601526 T7666 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 2601526 T7666 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 2601527 T7666 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51970/solr
   [junit4]   2> 2601527 T7666 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 2601528 T7666 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2601534 T7746 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@18ac21a6 name:ZooKeeperConnection Watcher:127.0.0.1:51970 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2601534 T7666 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2601542 T7666 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2601547 T7748 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@548ecef1 name:ZooKeeperConnection Watcher:127.0.0.1:51970/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2601548 T7666 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2601572 T7666 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2602581 T7666 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51986_
   [junit4]   2> 2602584 T7666 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51986_
   [junit4]   2> 2602611 T7666 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 2602612 T7666 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 2602615 T7698 oasha.CollectionsHandler.handleCreateAction Creating Collection : wt=javabin&collection.configName=conf1&router.name=compositeId&router.field=myOwnField&name=solrj_collection&replicationFactor=2&version=2&numShards=2&action=CREATE
   [junit4]   2> 2602618 T7688 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2602618 T7688 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2602618 T7688 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2602619 T7688 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2602619 T7688 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2602619 T7688 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2602619 T7688 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2602620 T7688 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2602620 T7688 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2602620 T7688 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2602620 T7688 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2602623 T7690 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000000 message:{
   [junit4]   2> 	  "operation":"createcollection",
   [junit4]   2> 	  "fromApi":"true",
   [junit4]   2> 	  "name":"solrj_collection",
   [junit4]   2> 	  "replicationFactor":"2",
   [junit4]   2> 	  "collection.configName":"conf1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "router.name":"compositeId",
   [junit4]   2> 	  "router.field":"myOwnField"}
   [junit4]   2> 2602625 T7750 oasc.OverseerCollectionProcessor.processMessage WARN OverseerCollectionProcessor.processMessage : createcollection , {
   [junit4]   2> 	  "operation":"createcollection",
   [junit4]   2> 	  "fromApi":"true",
   [junit4]   2> 	  "name":"solrj_collection",
   [junit4]   2> 	  "replicationFactor":"2",
   [junit4]   2> 	  "collection.configName":"conf1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "router.name":"compositeId",
   [junit4]   2> 	  "router.field":"myOwnField"}
   [junit4]   2> 2602626 T7750 oasc.OverseerCollectionProcessor.createConfNode creating collections conf node /collections/solrj_collection 
   [junit4]   2> 2602626 T7750 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection
   [junit4]   2> 2602638 T7688 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2602642 T7689 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2602644 T7689 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: solrj_collection
   [junit4]   2> 2602644 T7689 oasc.Overseer$ClusterStateUpdater.createCollection Create collection solrj_collection with shards [shard1, shard2]
   [junit4]   2> 2602651 T7688 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2602653 T7688 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 2602653 T7748 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 2602653 T7693 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 2602653 T7720 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 2602654 T7734 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 2602653 T7706 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 2602739 T7750 oasc.OverseerCollectionProcessor.createCollection Creating SolrCores for new collection solrj_collection, shardNames [shard1, shard2] , replicationFactor : 2
   [junit4]   2> 2602739 T7750 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica1 as part of slice shard1 of collection solrj_collection on 127.0.0.1:51980_
   [junit4]   2> 2602742 T7750 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica2 as part of slice shard1 of collection solrj_collection on 127.0.0.1:51983_
   [junit4]   2> 2602744 T7750 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica1 as part of slice shard2 of collection solrj_collection on 127.0.0.1:51977_
   [junit4]   2> 2602747 T7716 oasha.CoreAdminHandler.handleCreateAction core create command shard=shard1&qt=/admin/cores&wt=javabin&collection.configName=conf1&name=solrj_collection_shard1_replica1&version=2&numShards=2&collection=solrj_collection&action=CREATE
   [junit4]   2> 2602749 T7750 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica2 as part of slice shard2 of collection solrj_collection on 127.0.0.1:51973_
   [junit4]   2> 2602751 T7730 oasha.CoreAdminHandler.handleCreateAction core create command shard=shard1&qt=/admin/cores&wt=javabin&collection.configName=conf1&name=solrj_collection_shard1_replica2&version=2&numShards=2&collection=solrj_collection&action=CREATE
   [junit4]   2> 2602753 T7699 oasha.CoreAdminHandler.handleCreateAction core create command shard=shard2&qt=/admin/cores&wt=javabin&collection.configName=conf1&name=solrj_collection_shard2_replica1&version=2&numShards=2&collection=solrj_collection&action=CREATE
   [junit4]   2> 2602756 T7716 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica1 state=down collection=solrj_collection
   [junit4]   2> 2602756 T7699 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica1 state=down collection=solrj_collection
   [junit4]   2> 2602757 T7730 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica2 state=down collection=solrj_collection
   [junit4]   2> 2602761 T7716 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 2602763 T7699 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 2602761 T7688 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2602763 T7679 oasha.CoreAdminHandler.handleCreateAction core create command shard=shard2&qt=/admin/cores&wt=javabin&collection.configName=conf1&name=solrj_collection_shard2_replica2&version=2&numShards=2&collection=solrj_collection&action=CREATE
   [junit4]   2> 2602763 T7730 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 2602768 T7679 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica2 state=down collection=solrj_collection
   [junit4]   2> 2602769 T7689 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2602770 T7688 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2602771 T7679 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 2602771 T7689 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:51980",
   [junit4]   2> 	  "core":"solrj_collection_shard1_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:51980_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 2602781 T7689 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:51983",
   [junit4]   2> 	  "core":"solrj_collection_shard1_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:51983_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 2602788 T7688 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2602791 T7689 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:51977",
   [junit4]   2> 	  "core":"solrj_collection_shard2_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:51977_",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 2602797 T7688 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2602800 T7689 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:51973",
   [junit4]   2> 	  "core":"solrj_collection_shard2_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:51973_",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 2602807 T7688 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2602914 T7706 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 2602914 T7734 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 2602914 T7748 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 2602914 T7688 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 2602914 T7693 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 2602914 T7720 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 2603764 T7716 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica1
   [junit4]   2> 2603764 T7699 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica1
   [junit4]   2> 2603765 T7716 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-004/solr.xml
   [junit4]   2> 2603766 T7716 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 2603766 T7730 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica2
   [junit4]   2> 2603766 T7699 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-003/solr.xml
   [junit4]   2> 2603768 T7699 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 2603769 T7730 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-005/solr.xml
   [junit4]   2> 2603770 T7699 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 2603770 T7699 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 2603770 T7730 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 2603770 T7716 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 2603772 T7716 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 2603773 T7679 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica2
   [junit4]   2> 2603774 T7679 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-002/solr.xml
   [junit4]   2> 2603774 T7679 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 2603775 T7699 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 2603776 T7699 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-003/solrj_collection_shard2_replica1/'
   [junit4]   2> 2603775 T7730 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 2603776 T7730 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 2603779 T7679 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 2603779 T7679 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 2603781 T7679 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 2603781 T7679 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-002/solrj_collection_shard2_replica2/'
   [junit4]   2> 2603783 T7716 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 2603783 T7716 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-004/solrj_collection_shard1_replica1/'
   [junit4]   2> 2603791 T7730 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 2603791 T7730 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-005/solrj_collection_shard1_replica2/'
   [junit4]   2> 2603883 T7699 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
   [junit4]   2> 2603950 T7716 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
   [junit4]   2> 2604017 T7699 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 2604021 T7679 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
   [junit4]   2> 2604050 T7730 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
   [junit4]   2> 2604058 T7699 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 2604082 T7699 oass.IndexSchema.readSchema [solrj_collection_shard2_replica1] Schema name=test
   [junit4]   2> 2604184 T7716 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 2604187 T7716 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 2604208 T7716 oass.IndexSchema.readSchema [solrj_collection_shard1_replica1] Schema name=test
   [junit4]   2> 2604288 T7730 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 2604291 T7679 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 2604298 T7679 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 2604298 T7730 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 2604307 T7730 oass.IndexSchema.readSchema [solrj_collection_shard1_replica2] Schema name=test
   [junit4]   2> 2604322 T7679 oass.IndexSchema.readSchema [solrj_collection_shard2_replica2] Schema name=test
   [junit4]   2> 2605772 T7716 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 2605783 T7699 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 2605792 T7716 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 2605796 T7716 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 2605805 T7699 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 2605809 T7699 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 2605851 T7679 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 2605867 T7679 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 2605874 T7679 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 2605886 T7730 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 2605899 T7730 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 2605903 T7699 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2605911 T7730 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 2605916 T7716 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2605918 T7699 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2605927 T7699 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 2605927 T7716 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2605932 T7699 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 2605933 T7699 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 2605934 T7699 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 2605939 T7716 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 2605943 T7699 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 2605943 T7699 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 2605944 T7699 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica1' using configuration from collection solrj_collection
   [junit4]   2> 2605944 T7699 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 2605945 T7699 oasc.SolrCore.<init> [solrj_collection_shard2_replica1] Opening new SolrCore at ./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-003/solrj_collection_shard2_replica1/, dataDir=./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-003/solrj_collection_shard2_replica1/data/
   [junit4]   2> 2605946 T7699 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7469643d
   [junit4]   2> 2605945 T7716 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 2605949 T7716 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 2605949 T7699 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-003/solrj_collection_shard2_replica1/data
   [junit4]   2> 2605950 T7699 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-003/solrj_collection_shard2_replica1/data/index/
   [junit4]   2> 2605950 T7699 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica1] Solr index directory './solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-003/solrj_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 2605950 T7679 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2605949 T7716 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 2605951 T7699 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-003/solrj_collection_shard2_replica1/data/index
   [junit4]   2> 2605954 T7699 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=15, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7928932990316402]
   [junit4]   2> 2605956 T7716 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 2605957 T7716 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 2605958 T7716 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica1' using configuration from collection solrj_collection
   [junit4]   2> 2605958 T7716 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 2605958 T7716 oasc.SolrCore.<init> [solrj_collection_shard1_replica1] Opening new SolrCore at ./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-004/solrj_collection_shard1_replica1/, dataDir=./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-004/solrj_collection_shard1_replica1/data/
   [junit4]   2> 2605959 T7716 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7469643d
   [junit4]   2> 2605959 T7716 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-004/solrj_collection_shard1_replica1/data
   [junit4]   2> 2605960 T7716 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-004/solrj_collection_shard1_replica1/data/index/
   [junit4]   2> 2605960 T7716 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica1] Solr index directory './solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-004/solrj_collection_shard1_replica1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 2605960 T7679 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2605961 T7716 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-004/solrj_collection_shard1_replica1/data/index
   [junit4]   2> 2605962 T7716 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=15, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7928932990316402]
   [junit4]   2> 2605962 T7699 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@2624a14 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@52f5e41),segFN=segments_1,generation=1}
   [junit4]   2> 2605964 T7699 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2605969 T7679 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 2605971 T7699 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 2605972 T7679 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 2605972 T7699 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 2605972 T7679 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 2605974 T7679 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 2605973 T7699 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 2605979 T7699 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2605979 T7679 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 2605980 T7679 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 2605981 T7679 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica2' using configuration from collection solrj_collection
   [junit4]   2> 2605982 T7730 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2605979 T7716 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@4fa281a5 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6a350c0a),segFN=segments_1,generation=1}
   [junit4]   2> 2605983 T7716 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2605982 T7679 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 2605984 T7679 oasc.SolrCore.<init> [solrj_collection_shard2_replica2] Opening new SolrCore at ./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-002/solrj_collection_shard2_replica2/, dataDir=./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-002/solrj_collection_shard2_replica2/data/
   [junit4]   2> 2605984 T7679 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7469643d
   [junit4]   2> 2605980 T7699 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2605985 T7699 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 2605986 T7699 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2605986 T7699 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2605987 T7699 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 2605987 T7699 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 2605989 T7699 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 2605989 T7699 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 2605989 T7699 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 2605990 T7716 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 2605990 T7716 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 2605991 T7716 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 2605992 T7716 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2605992 T7716 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2605993 T7716 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 2605994 T7716 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2605994 T7730 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2605990 T7699 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 2605994 T7716 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2605996 T7716 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 2605993 T7679 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-002/solrj_collection_shard2_replica2/data
   [junit4]   2> 2605997 T7679 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-002/solrj_collection_shard2_replica2/data/index/
   [junit4]   2> 2605997 T7679 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica2] Solr index directory './solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-002/solrj_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
   [junit4]   2> 2605998 T7679 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-002/solrj_collection_shard2_replica2/data/index
   [junit4]   2> 2605999 T7679 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=15, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7928932990316402]
   [junit4]   2> 2605996 T7699 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 2606001 T7699 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 2606001 T7699 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 2605997 T7716 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 2606002 T7716 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 2606003 T7716 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 2606003 T7716 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 2606004 T7716 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 2606004 T7716 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 2606005 T7716 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 2606006 T7716 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 2606002 T7679 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@2bbe715f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@549087e6),segFN=segments_1,generation=1}
   [junit4]   2> 2606011 T7679 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2606002 T7730 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 2606018 T7699 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2606019 T7679 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 2606019 T7679 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 2606020 T7679 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 2606020 T7679 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2606020 T7679 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2606021 T7679 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 2606022 T7679 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2606023 T7679 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2606024 T7679 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 2606025 T7679 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 2606026 T7699 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 2606026 T7699 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 2606022 T7716 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2606028 T7699 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1148833443, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 2606026 T7679 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 2606029 T7679 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 2606029 T7679 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 2606030 T7679 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 2606031 T7679 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 2606032 T7699 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@2624a14 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@52f5e41),segFN=segments_1,generation=1}
   [junit4]   2> 2606032 T7699 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2606033 T7699 oass.SolrIndexSearcher.<init> Opening Searcher@1ef02c42[solrj_collection_shard2_replica1] main
   [junit4]   2> 2606033 T7699 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 2606034 T7730 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 2606034 T7730 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 2606035 T7730 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 2606032 T7679 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 2606035 T7716 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 2606038 T7716 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 2606039 T7730 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 2606039 T7730 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 2606040 T7730 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica2' using configuration from collection solrj_collection
   [junit4]   2> 2606040 T7679 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 2606039 T7699 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 2606042 T7699 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 2606041 T7716 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1148833443, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 2606043 T7699 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 2606043 T7699 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 2606044 T7699 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2606040 T7730 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 2606045 T7716 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@4fa281a5 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6a350c0a),segFN=segments_1,generation=1}
   [junit4]   2> 2606045 T7716 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2606045 T7730 oasc.SolrCore.<init> [solrj_collection_shard1_replica2] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-005/solrj_collection_shard1_replica2/, dataDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-005/solrj_collection_shard1_replica2/data/
   [junit4]   2> 2606047 T7730 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7469643d
   [junit4]   2> 2606046 T7699 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 2606047 T7699 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2606048 T7699 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 2606046 T7716 oass.SolrIndexSearcher.<init> Opening Searcher@746ade4a[solrj_collection_shard1_replica1] main
   [junit4]   2> 2606045 T7679 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2606049 T7716 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 2606048 T7699 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 2606047 T7730 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-005/solrj_collection_shard1_replica2/data
   [junit4]   2> 2606052 T7730 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-005/solrj_collection_shard1_replica2/data/index/
   [junit4]   2> 2606053 T7730 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica2] Solr index directory '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-005/solrj_collection_shard1_replica2/data/index' doesn't exist. Creating new index...
   [junit4]   2> 2606055 T7755 oasc.SolrCore.registerSearcher [solrj_collection_shard2_replica1] Registered new searcher Searcher@1ef02c42[solrj_collection_shard2_replica1] main{UninvertingDirectoryReader()}
   [junit4]   2> 2606058 T7679 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 2606059 T7679 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 2606058 T7699 oasc.CoreContainer.registerCore registering core: solrj_collection_shard2_replica1
   [junit4]   2> 2606060 T7699 oasc.ZkController.register Register replica - core:solrj_collection_shard2_replica1 address:http://127.0.0.1:51977 collection:solrj_collection shard:shard2
   [junit4]   2> 2606060 T7716 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 2606061 T7716 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 2606060 T7679 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1148833443, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 2606062 T7716 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 2606063 T7716 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 2606061 T7730 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solr.cloud.CollectionsAPIDistributedZkTest-3708010A5BE56C52-001/tempDir-005/solrj_collection_shard1_replica2/data/index
   [junit4]   2> 2606063 T7679 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@2bbe715f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@549087e6),segFN=segments_1,generation=1}
   [junit4]   2> 2606064 T7679 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2606063 T7699 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard2/election
   [junit4]   2> 2606063 T7716 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2606065 T7679 oass.SolrIndexSearcher.<init> Opening Searcher@7e37a07f[solrj_collection_shard2_replica2] main
   [junit4]   2> 2606067 T7679 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 2606064 T7730 oasu.RandomMergePolicy.<init> RandomMergePol

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

emory doPackFST= false), a_i1=PostingsFormat(name=Lucene41VarGapFixedInterval), multiDefault=Lucene41(blocksize=128), timestamp=PostingsFormat(name=Lucene41VarGapFixedInterval), range_facet_l=PostingsFormat(name=Lucene41VarGapFixedInterval), intDefault=PostingsFormat(name=Lucene41VarGapFixedInterval), a_t=PostingsFormat(name=Lucene41VarGapFixedInterval), text=PostingsFormat(name=FSTPulsing41), _version_=PostingsFormat(name=Lucene41VarGapFixedInterval), other_tl1=PostingsFormat(name=Lucene41VarGapFixedInterval)}, docValues:{timestamp=DocValuesFormat(name=Memory)}, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=de_AT, timezone=America/Halifax
   [junit4]   2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.7.0_55 (64-bit)/cpus=2,threads=2,free=133251792,total=391548928
   [junit4]   2> NOTE: All tests run in this JVM: [TestCoreContainer, BadComponentTest, DistributedSpellCheckComponentTest, CopyFieldTest, TestDefaultSearchFieldResource, ShardSplitTest, TestUniqueKeyFieldResource, TestReloadAndDeleteDocs, XsltUpdateRequestHandlerTest, EchoParamsTest, DOMUtilTest, TestHighlightDedupGrouping, TestConfigSets, TestCopyFieldCollectionResource, URLClassifyProcessorTest, OverseerStatusTest, SpatialFilterTest, TestSolrXml, RAMDirectoryFactoryTest, TestSolrQueryParserResource, SimplePostToolTest, HdfsWriteToMultipleCollectionsTest, TestRandomFaceting, OverseerCollectionProcessorTest, ChaosMonkeyNothingIsSafeTest, TestInitQParser, IndexSchemaTest, CurrencyFieldOpenExchangeTest, RequestHandlersTest, JsonLoaderTest, TestDistributedMissingSort, TestLazyCores, PeerSyncTest, DocumentBuilderTest, ExternalFileFieldSortTest, TestCollationFieldDocValues, SuggesterWFSTTest, UpdateRequestProcessorFactoryTest, UnloadDistributedZkTest, SuggesterFSTTest, PreAnalyzedUpdateProcessorTest, HdfsBasicDistributedZkTest, TestStressRecovery, TestManagedSchema, TestSurroundQueryParser, TestDocumentBuilder, SearchHandlerTest, InfoHandlerTest, TestSchemaResource, MultiTermTest, TestSolrXmlPersistor, TestFieldSortValues, TestSolrJ, FastVectorHighlighterTest, TestDistributedGrouping, TestManagedSchemaFieldResource, HighlighterTest, TestCloudManagedSchemaAddField, ParsingFieldUpdateProcessorsTest, DefaultValueUpdateProcessorTest, BasicFunctionalityTest, DistributedQueryComponentOptimizationTest, TestFastLRUCache, TestRandomMergePolicy, TestRTGBase, TestFieldCollectionResource, RecoveryZkTest, ChangedSchemaMergeTest, SpellCheckCollatorTest, TestNonNRTOpen, AddSchemaFieldsUpdateProcessorFactoryTest, UpdateParamsTest, SolrCmdDistributorTest, TestOrdValues, TestLuceneMatchVersion, TestManagedSynonymFilterFactory, RemoteQueryErrorTest, LukeRequestHandlerTest, HttpPartitionTest, AnalysisAfterCoreReloadTest, SpellPossibilityIteratorTest, TestManagedStopFilterFactory, BadIndexSchemaTest, TestIBSimilarityFactory, HighlighterConfigTest, TestComplexPhraseQParserPlugin, EnumFieldTest, ScriptEngineTest, TestRequestStatusCollectionAPI, TriLevelCompositeIdRoutingTest, TestPerFieldSimilarity, TestPseudoReturnFields, DebugComponentTest, TestReload, SyncSliceTest, TestCodecSupport, TestHashPartitioner, TestElisionMultitermQuery, TestSolrIndexConfig, ClusterStateTest, OutputWriterTest, TestDynamicFieldResource, SolrIndexConfigTest, TestStressUserVersions, ModifyConfFileTest, BinaryUpdateRequestHandlerTest, HdfsCollectionsAPIDistributedZkTest, TestStressLucene, TestFiltering, TestCollapseQParserPlugin, StatsComponentTest, TestBM25SimilarityFactory, TestCursorMarkWithoutUniqueKey, StatelessScriptUpdateProcessorFactoryTest, FunctionTest, TestAtomicUpdateErrorCases, NoFacetTest, TestStandardQParsers, BasicDistributedZk2Test, MigrateRouteKeyTest, TestFieldResource, HdfsLockFactoryTest, TestRestManager, ShardRoutingTest, ConvertedLegacyTest, DisMaxRequestHandlerTest, PrimitiveFieldTypeTest, SolrIndexSplitterTest, CurrencyFieldXmlFileTest, TestConfig, SynonymTokenizerTest, TestCSVResponseWriter, FieldMutatingUpdateProcessorTest, DirectUpdateHandlerTest, TestAddFieldRealTimeGet, DirectSolrConnectionTest, TimeZoneUtilsTest, TestImplicitCoreProperties, TestOverriddenPrefixQueryForCustomFieldType, ZkNodePropsTest, PreAnalyzedFieldTest, QueryResultKeyTest, NoCacheHeaderTest, MBeansHandlerTest, TestDistribDocBasedVersion, TestOmitPositions, CacheHeaderTest, DeleteInactiveReplicaTest, RankQueryTest, DistributedQueryComponentCustomSortTest, TermVectorComponentTest, ResponseLogComponentTest, TestCustomSort, ShowFileRequestHandlerTest, ReplicationFactorTest, PrimUtilsTest, QueryParsingTest, SliceStateTest, TestSchemaVersionResource, CustomCollectionTest, HdfsUnloadDistributedZkTest, TestRecovery, SolrPluginUtilsTest, ConnectionManagerTest, MoreLikeThisHandlerTest, TestDocBasedVersionConstraints, IndexBasedSpellCheckerTest, HardAutoCommitTest, TestQuerySenderListener, ReturnFieldsTest, TestSerializedLuceneMatchVersion, FullSolrCloudDistribCmdsTest, AddBlockUpdateTest, ExpressionTest, TestRemoteStreaming, CoreAdminRequestStatusTest, TestStressReorder, DocValuesMissingTest, TestClassNameShortening, DateFieldTest, LegacyHTMLStripCharFilterTest, TestFastOutputStream, CollectionsAPIAsyncDistributedZkTest, RangeFacetTest, TestSolrDeletionPolicy2, TestIndexingPerformance, TestFoldingMultitermQuery, FileUtilsTest, TestSchemaNameResource, HdfsRecoveryZkTest, FileBasedSpellCheckerTest, BasicDistributedZkTest, LeaderElectionIntegrationTest, TestModifyConfFiles, HdfsSyncSliceTest, TestAnalyzedSuggestions, ChaosMonkeySafeLeaderTest, CollectionsAPIDistributedZkTest]
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=CollectionsAPIDistributedZkTest -Dtests.seed=3708010A5BE56C52 -Dtests.slow=true -Dtests.locale=de_AT -Dtests.timezone=America/Halifax -Dtests.file.encoding=UTF-8
   [junit4] ERROR   0.00s | CollectionsAPIDistributedZkTest (suite) <<<
   [junit4]    > Throwable #1: java.lang.AssertionError: ERROR: SolrZkClient opens=18 closes=17
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([3708010A5BE56C52]:0)
   [junit4]    > 	at org.apache.solr.SolrTestCaseJ4.endTrackingZkClients(SolrTestCaseJ4.java:451)
   [junit4]    > 	at org.apache.solr.SolrTestCaseJ4.afterClass(SolrTestCaseJ4.java:185)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:745)Throwable #2: com.carrotsearch.randomizedtesting.ThreadLeakError: 2 threads leaked from SUITE scope at org.apache.solr.cloud.CollectionsAPIDistributedZkTest: 
   [junit4]    >    1) Thread[id=7822, name=TEST-CollectionsAPIDistributedZkTest.testDistribSearch-seed#[3708010A5BE56C52]-EventThread, state=WAITING, group=TGRP-CollectionsAPIDistributedZkTest]
   [junit4]    >         at sun.misc.Unsafe.park(Native Method)
   [junit4]    >         at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
   [junit4]    >         at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
   [junit4]    >         at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
   [junit4]    >         at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:494)
   [junit4]    >    2) Thread[id=7821, name=TEST-CollectionsAPIDistributedZkTest.testDistribSearch-seed#[3708010A5BE56C52]-SendThread(127.0.0.1:51970), state=TIMED_WAITING, group=TGRP-CollectionsAPIDistributedZkTest]
   [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([3708010A5BE56C52]:0)Throwable #3: com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
   [junit4]    >    1) Thread[id=7821, name=TEST-CollectionsAPIDistributedZkTest.testDistribSearch-seed#[3708010A5BE56C52]-SendThread(127.0.0.1:51970), state=TIMED_WAITING, group=TGRP-CollectionsAPIDistributedZkTest]
   [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([3708010A5BE56C52]:0)
   [junit4] Completed in 148.85s, 1 test, 2 failures, 2 errors <<< FAILURES!

[...truncated 605 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:467: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:447: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:45: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/extra-targets.xml:37: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build.xml:189: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/common-build.xml:496: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:1296: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:920: There were test failures: 406 suites, 1688 tests, 3 suite-level errors, 1 failure, 787 ignored (8 assumptions)

Total time: 86 minutes 44 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure