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 2013/10/21 16:39:35 UTC

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

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

1 tests failed.
REGRESSION:  org.apache.solr.cloud.CustomCollectionTest.testDistribSearch

Error Message:
collection already exists: implicitcoll0

Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: collection already exists: implicitcoll0
	at __randomizedtesting.SeedInfo.seed([BFE5884AFE79729B:3E030652892612A7]:0)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:464)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
	at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:268)
	at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:636)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1580)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1542)
	at org.apache.solr.cloud.CustomCollectionTest.testCustomCollectionsAPI(CustomCollectionTest.java:190)
	at org.apache.solr.cloud.CustomCollectionTest.doTest(CustomCollectionTest.java:133)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	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:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	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.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	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:70)
	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:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	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 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:70)
	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:358)
	at java.lang.Thread.run(Thread.java:744)




Build Log:
[...truncated 9684 lines...]
   [junit4] Suite: org.apache.solr.cloud.CustomCollectionTest
   [junit4]   2> 25713 T21 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /fm/c
   [junit4]   2> 25756 T21 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-CustomCollectionTest-1382362661565
   [junit4]   2> 25785 T21 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 25818 T22 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 26120 T21 oasc.ZkTestServer.run start zk server on port:49155
   [junit4]   2> 26372 T21 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 26784 T23 oazs.NIOServerCnxn.doIO WARN Exception causing close of session 0x0 due to java.io.IOException: ZooKeeperServer not running
   [junit4]   2> 28052 T28 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5e506d2d name:ZooKeeperConnection Watcher:127.0.0.1:49155 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 28053 T21 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 28059 T21 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 28186 T21 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 28186 T23 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x141db3c44b10000, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 28207 T30 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15115676 name:ZooKeeperConnection Watcher:127.0.0.1:49155/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 28208 T21 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 28238 T21 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 28257 T21 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 28272 T21 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 28281 T21 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 28296 T21 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 28331 T21 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 28349 T21 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 28350 T21 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 28362 T21 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 28365 T21 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 28382 T21 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 28384 T21 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 28397 T21 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 28399 T21 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 28412 T21 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 28414 T21 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 28427 T21 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 28429 T21 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 28442 T21 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 28444 T21 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 28465 T21 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 28468 T21 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 28485 T21 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 28486 T21 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 29688 T21 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 30151 T21 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49159
   [junit4]   2> 30227 T21 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 30229 T21 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 30230 T21 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-controljetty-1382362664309
   [junit4]   2> 30231 T21 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-controljetty-1382362664309/'
   [junit4]   2> 30301 T21 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/./org.apache.solr.cloud.CustomCollectionTest-controljetty-1382362664309/solr.xml
   [junit4]   2> 30478 T21 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 30487 T21 oasc.CoreContainer.<init> New CoreContainer 1008252300
   [junit4]   2> 30489 T21 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-controljetty-1382362664309/]
   [junit4]   2> 30558 T21 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 30559 T21 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 30560 T21 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 30562 T21 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 30563 T21 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 30563 T21 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 30564 T21 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 30565 T21 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 30566 T21 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 30573 T21 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 30574 T21 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 30576 T21 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49155/solr
   [junit4]   2> 30613 T21 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 30619 T21 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 30635 T42 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@746b64d7 name:ZooKeeperConnection Watcher:127.0.0.1:49155 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 30640 T21 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 30681 T21 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 30694 T44 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4944b48c name:ZooKeeperConnection Watcher:127.0.0.1:49155/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 30695 T21 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 30716 T21 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 30755 T21 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 30792 T21 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 30800 T21 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49159_fm%2Fc
   [junit4]   2> 30811 T21 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49159_fm%2Fc
   [junit4]   2> 30832 T21 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 30878 T21 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 30886 T21 oasc.Overseer.start Overseer (id=90594519421091843-127.0.0.1:49159_fm%2Fc-n_0000000000) starting
   [junit4]   2> 30932 T21 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 30966 T46 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 30970 T21 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 30984 T21 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 31001 T21 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 31037 T45 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 31051 T21 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /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/./org.apache.solr.cloud.CustomCollectionTest-controljetty-1382362664309
   [junit4]   2> 31271 T21 oasc.CorePropertiesLocator.discoverUnder Found core conf in /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/./org.apache.solr.cloud.CustomCollectionTest-controljetty-1382362664309/conf/
   [junit4]   2> 31284 T21 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 31286 T21 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 31286 T21 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 31429 T21 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 31435 T49 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f2d3988 name:ZooKeeperConnection Watcher:127.0.0.1:49155/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 31436 T21 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 31442 T21 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 31456 T21 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
   [junit4]   2> 31928 T21 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 31933 T21 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49163
   [junit4]   2> 31936 T21 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 31937 T21 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 31938 T21 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CustomCollectionTest-jetty1-1382362667264
   [junit4]   2> 31939 T21 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CustomCollectionTest-jetty1-1382362667264/'
   [junit4]   2> 32000 T21 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty1-1382362667264/solr.xml
   [junit4]   2> 32181 T21 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 32182 T21 oasc.CoreContainer.<init> New CoreContainer 1841752342
   [junit4]   2> 32183 T21 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CustomCollectionTest-jetty1-1382362667264/]
   [junit4]   2> 32187 T21 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 32188 T21 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 32188 T21 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 32189 T21 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 32190 T21 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 32191 T21 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 32191 T21 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 32192 T21 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 32193 T21 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 32200 T21 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 32201 T21 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 32202 T21 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49155/solr
   [junit4]   2> 32203 T21 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 32205 T21 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 32212 T60 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@63e31115 name:ZooKeeperConnection Watcher:127.0.0.1:49155 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 32214 T21 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 32226 T21 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 32231 T62 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7a62173f name:ZooKeeperConnection Watcher:127.0.0.1:49155/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 32232 T21 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 32254 T21 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 33271 T21 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49163_fm%2Fc
   [junit4]   2> 33274 T21 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49163_fm%2Fc
   [junit4]   2> 33292 T44 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 33295 T49 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 33296 T62 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 33317 T21 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty1-1382362667264
   [junit4]   2> 33450 T21 oasc.CorePropertiesLocator.discoverUnder Found core conf in /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty1-1382362667264/conf/
   [junit4]   2> 33457 T21 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 33459 T21 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 33460 T21 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 33928 T21 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 33936 T21 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49166
   [junit4]   2> 33939 T21 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 33941 T21 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 33942 T21 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty2-1382362669273
   [junit4]   2> 33942 T21 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty2-1382362669273/'
   [junit4]   2> 34004 T21 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/./org.apache.solr.cloud.CustomCollectionTest-jetty2-1382362669273/solr.xml
   [junit4]   2> 34161 T21 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 34163 T21 oasc.CoreContainer.<init> New CoreContainer 1227354218
   [junit4]   2> 34163 T21 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty2-1382362669273/]
   [junit4]   2> 34166 T21 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 34167 T21 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 34168 T21 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 34169 T21 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 34170 T21 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 34171 T21 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 34171 T21 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 34172 T21 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 34173 T21 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 34180 T21 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 34181 T21 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 34183 T21 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49155/solr
   [junit4]   2> 34184 T21 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 34186 T21 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 34193 T74 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2b6ef00d name:ZooKeeperConnection Watcher:127.0.0.1:49155 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 34194 T21 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 34204 T21 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 34212 T76 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3a477231 name:ZooKeeperConnection Watcher:127.0.0.1:49155/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 34215 T21 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 34235 T21 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 35247 T21 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49166_fm%2Fc
   [junit4]   2> 35250 T21 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49166_fm%2Fc
   [junit4]   2> 35260 T76 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 35261 T49 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 35262 T44 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 35262 T62 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 35275 T21 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /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/./org.apache.solr.cloud.CustomCollectionTest-jetty2-1382362669273
   [junit4]   2> 35492 T21 oasc.CorePropertiesLocator.discoverUnder Found core conf in /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/./org.apache.solr.cloud.CustomCollectionTest-jetty2-1382362669273/conf/
   [junit4]   2> 35505 T21 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 35506 T21 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 35507 T21 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 35980 T21 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 35986 T21 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49169
   [junit4]   2> 35989 T21 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 35990 T21 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 35991 T21 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CustomCollectionTest-jetty3-1382362671321
   [junit4]   2> 35992 T21 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CustomCollectionTest-jetty3-1382362671321/'
   [junit4]   2> 36040 T21 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty3-1382362671321/solr.xml
   [junit4]   2> 36216 T21 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 36217 T21 oasc.CoreContainer.<init> New CoreContainer 2026882409
   [junit4]   2> 36218 T21 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CustomCollectionTest-jetty3-1382362671321/]
   [junit4]   2> 36222 T21 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 36223 T21 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 36224 T21 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 36225 T21 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 36226 T21 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 36226 T21 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 36227 T21 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 36228 T21 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 36228 T21 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 36234 T21 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 36236 T21 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 36236 T21 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49155/solr
   [junit4]   2> 36237 T21 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 36240 T21 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 36248 T88 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5a191240 name:ZooKeeperConnection Watcher:127.0.0.1:49155 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 36249 T21 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 36264 T21 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 36271 T90 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@32dc44ff name:ZooKeeperConnection Watcher:127.0.0.1:49155/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 36272 T21 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 36293 T21 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 37306 T21 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49169_fm%2Fc
   [junit4]   2> 37309 T21 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49169_fm%2Fc
   [junit4]   2> 37325 T44 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 37325 T62 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 37325 T49 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 37329 T76 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 37329 T90 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 37348 T21 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty3-1382362671321
   [junit4]   2> 37494 T21 oasc.CorePropertiesLocator.discoverUnder Found core conf in /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty3-1382362671321/conf/
   [junit4]   2> 37502 T21 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 37505 T21 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 37506 T21 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 38007 T21 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 38014 T21 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49172
   [junit4]   2> 38017 T21 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 38019 T21 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 38020 T21 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CustomCollectionTest-jetty4-1382362673320
   [junit4]   2> 38020 T21 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CustomCollectionTest-jetty4-1382362673320/'
   [junit4]   2> 38071 T21 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty4-1382362673320/solr.xml
   [junit4]   2> 38233 T21 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 38235 T21 oasc.CoreContainer.<init> New CoreContainer 1093166539
   [junit4]   2> 38236 T21 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CustomCollectionTest-jetty4-1382362673320/]
   [junit4]   2> 38239 T21 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 38240 T21 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 38240 T21 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 38241 T21 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 38242 T21 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 38243 T21 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 38243 T21 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 38245 T21 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 38246 T21 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 38252 T21 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 38253 T21 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 38253 T21 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49155/solr
   [junit4]   2> 38254 T21 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 38256 T21 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 38263 T102 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@74fb7929 name:ZooKeeperConnection Watcher:127.0.0.1:49155 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 38264 T21 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 38276 T21 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 38281 T104 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2bfe621e name:ZooKeeperConnection Watcher:127.0.0.1:49155/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 38282 T21 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 38298 T21 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 39313 T21 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49172_fm%2Fc
   [junit4]   2> 39316 T21 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49172_fm%2Fc
   [junit4]   2> 39334 T44 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 39336 T49 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 39337 T90 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 39337 T62 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 39337 T76 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 39339 T104 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 39356 T21 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty4-1382362673320
   [junit4]   2> 39494 T21 oasc.CorePropertiesLocator.discoverUnder Found core conf in /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty4-1382362673320/conf/
   [junit4]   2> 39502 T21 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 39504 T21 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 39504 T21 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 39513 T21 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 39519 T107 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7ed34a97 name:ZooKeeperConnection Watcher:127.0.0.1:49155/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 39520 T21 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 39526 T21 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 39553 T21 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 39559 T109 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f007fc0 name:ZooKeeperConnection Watcher:127.0.0.1:49155/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 39560 T21 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 39566 T21 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 40826 T71 oasha.CollectionsHandler.handleCreateAction Creating Collection : shards=a,b,c&maxShardsPerNode=5&name=implicitcoll0&replicationFactor=5&action=CREATE&wt=javabin&router.name=implicit&version=2
   [junit4]   2> 40834 T44 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 40847 T46 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000000 message:{
   [junit4]   2> 	  "operation":"createcollection",
   [junit4]   2> 	  "shards":"a,b,c",
   [junit4]   2> 	  "maxShardsPerNode":"5",
   [junit4]   2> 	  "name":"implicitcoll0",
   [junit4]   2> 	  "replicationFactor":"5",
   [junit4]   2> 	  "router.name":"implicit"}
   [junit4]   2> 40850 T46 oasc.OverseerCollectionProcessor.processMessage WARN OverseerCollectionProcessor.processMessage : createcollection , {
   [junit4]   2> 	  "operation":"createcollection",
   [junit4]   2> 	  "shards":"a,b,c",
   [junit4]   2> 	  "maxShardsPerNode":"5",
   [junit4]   2> 	  "name":"implicitcoll0",
   [junit4]   2> 	  "replicationFactor":"5",
   [junit4]   2> 	  "router.name":"implicit"}
   [junit4]   2> 41622 T45 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 41624 T45 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: implicitcoll0
   [junit4]   2> 41625 T45 oasc.Overseer$ClusterStateUpdater.createCollection Create collection implicitcoll0 with shards [a, b, c]
   [junit4]   2> 41686 T44 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> 41689 T104 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> 41688 T107 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> 41687 T76 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> 41690 T62 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> 41690 T90 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> 41690 T49 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> 41689 T109 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> 41773 T46 oasc.OverseerCollectionProcessor.createCollection going to create cores replicas shardNames [a, b, c] , repFactor : 5
   [junit4]   2> 41774 T46 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_a_replica1 as part of slice a of collection implicitcoll0 on 127.0.0.1:49172_fm%2Fc
   [junit4]   2> 41794 T46 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_a_replica2 as part of slice a of collection implicitcoll0 on 127.0.0.1:49166_fm%2Fc
   [junit4]   2> 41796 T46 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_a_replica3 as part of slice a of collection implicitcoll0 on 127.0.0.1:49163_fm%2Fc
   [junit4]   2> 41797 T46 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_a_replica4 as part of slice a of collection implicitcoll0 on 127.0.0.1:49169_fm%2Fc
   [junit4]   2> 41800 T46 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_a_replica5 as part of slice a of collection implicitcoll0 on 127.0.0.1:49159_fm%2Fc
   [junit4]   2> 41802 T46 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_b_replica1 as part of slice b of collection implicitcoll0 on 127.0.0.1:49172_fm%2Fc
   [junit4]   2> 41805 T46 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_b_replica2 as part of slice b of collection implicitcoll0 on 127.0.0.1:49166_fm%2Fc
   [junit4]   2> 41808 T46 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_b_replica3 as part of slice b of collection implicitcoll0 on 127.0.0.1:49163_fm%2Fc
   [junit4]   2> 41810 T46 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_b_replica4 as part of slice b of collection implicitcoll0 on 127.0.0.1:49169_fm%2Fc
   [junit4]   2> 41812 T46 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_b_replica5 as part of slice b of collection implicitcoll0 on 127.0.0.1:49159_fm%2Fc
   [junit4]   2> 41815 T46 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_c_replica1 as part of slice c of collection implicitcoll0 on 127.0.0.1:49172_fm%2Fc
   [junit4]   2> 41838 T46 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_c_replica2 as part of slice c of collection implicitcoll0 on 127.0.0.1:49166_fm%2Fc
   [junit4]   2> 41841 T46 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_c_replica3 as part of slice c of collection implicitcoll0 on 127.0.0.1:49163_fm%2Fc
   [junit4]   2> 41843 T46 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_c_replica4 as part of slice c of collection implicitcoll0 on 127.0.0.1:49169_fm%2Fc
   [junit4]   2> 41844 T46 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_c_replica5 as part of slice c of collection implicitcoll0 on 127.0.0.1:49159_fm%2Fc
   [junit4]   2> 41972 T38 oasc.ZkController.publish publishing core=implicitcoll0_c_replica5 state=down
   [junit4]   2> 41980 T98 oasc.ZkController.publish publishing core=implicitcoll0_a_replica1 state=down
   [junit4]   2> 41980 T70 oasc.ZkController.publish publishing core=implicitcoll0_b_replica2 state=down
   [junit4]   2> 41980 T67 oasc.ZkController.publish publishing core=implicitcoll0_a_replica2 state=down
   [junit4]   2> 41979 T100 oasc.ZkController.publish publishing core=implicitcoll0_c_replica1 state=down
   [junit4]   2> 41979 T35 oasc.ZkController.publish publishing core=implicitcoll0_b_replica5 state=down
   [junit4]   2> 41974 T36 oasc.ZkController.publish publishing core=implicitcoll0_a_replica5 state=down
   [junit4]   2> 41978 T55 oasc.ZkController.publish publishing core=implicitcoll0_b_replica3 state=down
   [junit4]   2> 41978 T85 oasc.ZkController.publish publishing core=implicitcoll0_b_replica4 state=down
   [junit4]   2> 41978 T69 oasc.ZkController.publish publishing core=implicitcoll0_c_replica2 state=down
   [junit4]   2> 42004 T67 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 42005 T38 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 42006 T100 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 41977 T54 oasc.ZkController.publish publishing core=implicitcoll0_a_replica3 state=down
   [junit4]   2> 42009 T55 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 42010 T36 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 41977 T83 oasc.ZkController.publish publishing core=implicitcoll0_c_replica4 state=down
   [junit4]   2> 41977 T53 oasc.ZkController.publish publishing core=implicitcoll0_c_replica3 state=down
   [junit4]   2> 41976 T84 oasc.ZkController.publish publishing core=implicitcoll0_a_replica4 state=down
   [junit4]   2> 42015 T69 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 41974 T99 oasc.ZkController.publish publishing core=implicitcoll0_b_replica1 state=down
   [junit4]   2> 42014 T85 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 42030 T83 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 42009 T35 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 42037 T54 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 42038 T53 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 42004 T70 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 41999 T98 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 42057 T84 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 42062 T99 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 43223 T45 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 43230 T45 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:49172/fm/c",
   [junit4]   2> 	  "core":"implicitcoll0_a_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:49172_fm%2Fc",
   [junit4]   2> 	  "shard":"a",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"implicitcoll0",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 43245 T45 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:49159/fm/c",
   [junit4]   2> 	  "core":"implicitcoll0_c_replica5",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:49159_fm%2Fc",
   [junit4]   2> 	  "shard":"c",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"implicitcoll0",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 43258 T45 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:49166/fm/c",
   [junit4]   2> 	  "core":"implicitcoll0_b_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:49166_fm%2Fc",
   [junit4]   2> 	  "shard":"b",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"implicitcoll0",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node3"}
   [junit4]   2> 43273 T45 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:49172/fm/c",
   [junit4]   2> 	  "core":"implicitcoll0_c_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:49172_fm%2Fc",
   [junit4]   2> 	  "shard":"c",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"implicitcoll0",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node4"}
   [junit4]   2> 43288 T45 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:49166/fm/c",
   [junit4]   2> 	  "core":"implicitcoll0_a_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:49166_fm%2Fc",
   [junit4]   2> 	  "shard":"a",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"implicitcoll0",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node5"}
   [junit4]   2> 43313 T45 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:49159/fm/c",
   [junit4]   2> 	  "core":"implicitcoll0_b_replica5",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:49159_fm%2Fc",
   [junit4]   2> 	  "shard":"b",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"implicitcoll0",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node6"}
   [junit4]   2> 43330 T45 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:49163/fm/c",
   [junit4]   2> 	  "core":"implicitcoll0_b_replica3",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:49163_fm%2Fc",
   [junit4]   2> 	  "shard":"b",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"implicitcoll0",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node7"}
   [junit4]   2> 43345 T45 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:49159/fm/c",
   [junit4]   2> 	  "core":"implicitcoll0_a_replica5",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:49159_fm%2Fc",
   [junit4]   2> 	  "shard":"a",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"implicitcoll0",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node8"}
   [junit4]   2> 43364 T45 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:49169/fm/c",
   [junit4]   2> 	  "core":"implicitcoll0_b_replica4",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:49169_fm%2Fc",
   [junit4]   2> 	  "shard":"b",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"implicitcoll0",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node9"}
   [junit4]   2> 43382 T45 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:49166/fm/c",
   [junit4]   2> 	  "core":"implicitcoll0_c_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:49166_fm%2Fc",
   [junit4]   2> 	  "shard":"c",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"implicitcoll0",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node10"}
   [junit4]   2> 43398 T45 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:49163/fm/c",
   [junit4]   2> 	  "core":"implicitcoll0_a_replica3",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:49163_fm%2Fc",
   [junit4]   2> 	  "shard":"a",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"implicitcoll0",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node11"}
   [junit4]   2> 43412 T45 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:49169/fm/c",
   [junit4]   2> 	  "core":"implicitcoll0_c_replica4",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:49169_fm%2Fc",
   [junit4]   2> 	  "shard":"c",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"implicitcoll0",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node12"}
   [junit4]   2> 43427 T45 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:49163/fm/c",
   [junit4]   2> 	  "core":"implicitcoll0_c_replica3",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:49163_fm%2Fc",
   [junit4]   2> 	  "shard":"c",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"implicitcoll0",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node13"}
   [junit4]   2> 43442 T45 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:49169/fm/c",
   [junit4]   2> 	  "core":"implicitcoll0_a_replica4",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:49169_fm%2Fc",
   [junit4]   2> 	  "shard":"a",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"implicitcoll0",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node14"}
   [junit4]   2> 43457 T45 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:49172/fm/c",
   [junit4]   2> 	  "core":"implicitcoll0_b_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:49172_fm%2Fc",
   [junit4]   2> 	  "shard":"b",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "shard_parent":null,
   [junit4]   2> 	  "collection":"implicitcoll0",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node15"}
   [junit4]   2> 43474 T44 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> 43476 T109 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> 43476 T90 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> 43478 T62 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> 43478 T104 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> 43477 T49 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> 43480 T76 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> 43479 T107 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> 44011 T38 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_c_replica5
   [junit4]   2> 44011 T67 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_a_replica2
   [junit4]   2> 44015 T55 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_b_replica3
   [junit4]   2> 44018 T36 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_a_replica5
   [junit4]   2> 44011 T100 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_c_replica1
   [junit4]   2> 44028 T67 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_a_replica2' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty2-1382362669273/implicitcoll0_a_replica2
   [junit4]   2> 44029 T67 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
   [junit4]   2> 44030 T85 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_b_replica4
   [junit4]   2> 44033 T55 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_b_replica3' using instanceDir: ./org.apache.solr.cloud.CustomCollectionTest-jetty1-1382362667264/implicitcoll0_b_replica3
   [junit4]   2> 44033 T55 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
   [junit4]   2> 44030 T69 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_c_replica2
   [junit4]   2> 44036 T83 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_c_replica4
   [junit4]   2> 44030 T38 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_c_replica5' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-controljetty-1382362664309/implicitcoll0_c_replica5
   [junit4]   2> 44040 T38 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
   [junit4]   2> 44041 T67 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:implicitcoll0
   [junit4]   2> 44042 T67 oasc.ZkController.getConfName Looking for collection configName
   [junit4]   2> 44031 T36 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_a_replica5' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-controljetty-1382362664309/implicitcoll0_a_replica5
   [junit4]   2> 44044 T36 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
   [junit4]   2> 44045 T35 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_b_replica5
   [junit4]   2> 44044 T54 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_a_replica3
   [junit4]   2> 44049 T67 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
   [junit4]   2> 44050 T67 oascc.SolrZkClient.makePath makePath: /collections/implicitcoll0
   [junit4]   2> 44044 T53 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_c_replica3
   [junit4]   2> 44053 T38 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:implicitcoll0
   [junit4]   2> 44054 T38 oasc.ZkController.getConfName Looking for collection configName
   [junit4]   2> 44041 T55 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:implicitcoll0
   [junit4]   2> 44057 T55 oasc.ZkController.getConfName Looking for collection configName
   [junit4]   2> 44040 T69 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_c_replica2' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty2-1382362669273/implicitcoll0_c_replica2
   [junit4]   2> 44059 T69 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
   [junit4]   2> 44039 T83 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_c_replica4' using instanceDir: ./org.apache.solr.cloud.CustomCollectionTest-jetty3-1382362671321/implicitcoll0_c_replica4
   [junit4]   2> 44061 T83 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
   [junit4]   2> 44063 T84 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_a_replica4
   [junit4]   2> 44066 T36 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:implicitcoll0
   [junit4]   2> 44066 T36 oasc.ZkController.getConfName Looking for collection configName
   [junit4]   2> 44034 T100 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_c_replica1' using instanceDir: ./org.apache.solr.cloud.CustomCollectionTest-jetty4-1382362673320/implicitcoll0_c_replica1
   [junit4]   2> 44068 T69 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:implicitcoll0
   [junit4]   2> 44069 T69 oasc.ZkController.getConfName Looking for collection configName
   [junit4]   2> 44034 T85 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_b_replica4' using instanceDir: ./org.apache.solr.cloud.CustomCollectionTest-jetty3-1382362671321/implicitcoll0_b_replica4
   [junit4]   2> 44071 T85 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
   [junit4]   2> 44069 T99 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_b_replica1
   [junit4]   2> 44068 T100 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
   [junit4]   2> 44068 T84 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_a_replica4' using instanceDir: ./org.apache.solr.cloud.CustomCollectionTest-jetty3-1382362671321/implicitcoll0_a_replica4
   [junit4]   2> 44074 T84 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
   [junit4]   2> 44075 T99 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_b_replica1' using instanceDir: ./org.apache.solr.cloud.CustomCollectionTest-jetty4-1382362673320/implicitcoll0_b_replica1
   [junit4]   2> 44076 T99 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
   [junit4]   2> 44057 T53 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_c_replica3' using instanceDir: ./org.apache.solr.cloud.CustomCollectionTest-jetty1-1382362667264/implicitcoll0_c_replica3
   [junit4]   2> 44078 T53 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
   [junit4]   2> 44052 T54 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_a_replica3' using instanceDir: ./org.apache.solr.cloud.CustomCollectionTest-jetty1-1382362667264/implicitcoll0_a_replica3
   [junit4]   2> 44081 T54 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
   [junit4]   2> 44083 T67 oasc.ZkController.readConfigName Load collection config from:/collections/implicitcoll0
   [junit4]   2> 44051 T35 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_b_replica5' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-controljetty-1382362664309/implicitcoll0_b_replica5
   [junit4]   2> 44086 T35 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
   [junit4]   2> 44045 T98 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_a_replica1
   [junit4]   2> 44044 T70 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_b_replica2
   [junit4]   2> 44091 T53 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 44092 T53 oasc.ZkController.readConfigName Load collection config from:/collections/implicitcoll0
   [junit4]   2> 44086 T85 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 44094 T85 oasc.ZkController.readConfigName Load collection config from:/collections/implicitcoll0
   [junit4]   2> 44096 T69 oascc.SolrZkClient.makePath makePath: /collections/implicitcoll0
   [junit4]   2> 44084 T84 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 44098 T84 oasc.ZkController.readConfigName Load collection config from:/collections/implicitcoll0
   [junit4]   2> 44083 T99 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 44101 T99 oasc.ZkController.readConfigName Load collection config from:/collections/implicitcoll0
   [junit4]   2> 44083 T100 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 44104 T100 oasc.ZkController.readConfigName Load collection config from:/collections/implicitcoll0
   [junit4]   2> 44077 T83 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 44106 T83 oasc.ZkController.readConfigName Load collection config from:/collections/implicitcoll0
   [junit4]   2> 44071 T55 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
   [junit4]   2> 44107 T55 oascc.SolrZkClient.makePath makePath: /collections/implicitcoll0
   [junit4]   2> 44109 T53 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CustomCollectionTest-jetty1-1382362667264/implicitcoll0_c_replica3/'
   [junit4]   2> 44104 T67 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty2-1382362669273/implicitcoll0_a_replica2/'
   [junit4]   2> 44093 T54 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 44119 T54 oasc.ZkController.readConfigName Load collection config from:/collections/implicitcoll0
   [junit4]   2> 44093 T70 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_b_replica2' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty2-1382362669273/implicitcoll0_b_replica2
   [junit4]   2> 44121 T70 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
   [junit4]   2> 44093 T98 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_a_replica1' using instanceDir: ./org.apache.solr.cloud.CustomCollectionTest-jetty4-1382362673320/implicitcoll0_a_replica1
   [junit4]   2> 44123 T98 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
   [junit4]   2> 44125 T38 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
   [junit4]   2> 44119 T85 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CustomCollectionTest-jetty3-1382362671321/implicitcoll0_b_replica4/'
   [junit4]   2> 44150 T99 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CustomCollectionTest-jetty4-1382362673320/implicitcoll0_b_replica1/'
   [junit4]   2> 44150 T100 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CustomCollectionTest-jetty4-1382362673320/implicitcoll0_c_replica1/'
   [junit4]   2> 44146 T70 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 44158 T70 oasc.ZkController.readConfigName Load collection config from:/collections/implicitcoll0
   [junit4]   2> 44146 T69 oasc.ZkController.readConfigName Load collection config from:/collections/implicitcoll0
   [junit4]   2> 44145 T98 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 44164 T98 oasc.ZkController.readConfigName Load collection config from:/collections/implicitcoll0
   [junit4]   2> 44143 T83 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CustomCollectionTest-jetty3-1382362671321/implicitcoll0_c_replica4/'
   [junit4]   2> 44166 T38 oascc.SolrZkClient.makePath makePath: /collections/implicitcoll0
   [junit4]   2> 44140 T36 oascc.SolrZkClient.makePath makePath: /collections/implicitcoll0
   [junit4]   2> 44139 T35 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 44171 T35 oasc.ZkController.readConfigName Load collection config from:/collections/implicitcoll0
   [junit4]   2> 44125 T84 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CustomCollectionTest-jetty3-1382362671321/implicitcoll0_a_replica4/'
   [junit4]   2> 44159 T54 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CustomCollectionTest-jetty1-1382362667264/implicitcoll0_a_replica3/'
   [junit4]   2> 44175 T55 oasc.ZkController.readConfigName Load collection config from:/collections/implicitcoll0
   [junit4]   2> 44198 T98 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CustomCollectionTest-jetty4-1382362673320/implicitcoll0_a_replica1/'
   [junit4]   2> 44201 T70 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty2-1382362669273/implicitcoll0_b_replica2/'
   [junit4]   2> 44202 T69 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-jetty2-1382362669273/implicitcoll0_c_replica2/'
   [junit4]   2> 44206 T35 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-controljetty-1382362664309/implicitcoll0_b_replica5/'
   [junit4]   2> 44206 T55 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CustomCollectionTest-jetty1-1382362667264/implicitcoll0_b_replica3/'
   [junit4]   2> 44219 T38 oasc.ZkController.readConfigName Load collection config from:/collections/implicitcoll0
   [junit4]   2> 44228 T36 oasc.ZkController.readConfigName Load collection config from:/collections/implicitcoll0
   [junit4]   2> 44236 T38 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-controljetty-1382362664309/implicitcoll0_c_replica5/'
   [junit4]   2> 44255 T36 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-controljetty-1382362664309/implicitcoll0_a_replica5/'
   [junit4]   2> 46072 T35 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 46137 T70 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 46175 T69 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 46245 T85 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 46560 T53 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 46694 T98 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 46700 T84 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 46714 T36 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 46725 T100 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 46777 T55 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 47019 T54 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 47367 T67 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 47488 T38 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 47589 T83 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 47725 T99 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 48133 T35 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 48197 T35 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 48607 T35 oass.IndexSchema.readSchema [implicitcoll0_b_replica5] Schema name=test
   [junit4]   2> 48674 T53 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 48694 T53 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 48997 T85 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 49039 T85 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 49278 T100 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 49280 T36 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 49399 T84 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 49420 T36 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 49432 T100 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 49445 T84 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 49451 T38 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 49542 T54 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 49597 T38 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 49601 T54 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 49620 T70 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 49629 T69 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 49637 T70 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 49640 T69 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 49929 T55 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 49933 T53 oass.IndexSchema.readSchema [implicitcoll0_c_replica3] Schema name=test
   [junit4]   2> 49945 T55 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 49961 T83 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 49969 T98 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 50047 T98 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 50060 T83 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 50324 T67 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 50489 T67 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 50530 T99 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 50551 T99 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 50778 T84 oass.IndexSchema.readSchema [implicitcoll0_a_replica4] Schema name=test
   [junit4]   2> 50809 T100 oass.IndexSchema.readSchema [implicitcoll0_c_replica1] Schema name=test
   [junit4]   2> 50982 T85 oass.IndexSchema.readSchema [implicitcoll0_b_replica4] Schema name=test
   [junit4]   2> 51207 T54 oass.IndexSchema.readSchema [implicitcoll0_a_replica3] Schema name=test
   [junit4]   2> 51318 T69 oass.IndexSchema.readSchema [implicitcoll0_c_replica2] Schema name=test
   [junit4]   2> 51333 T38 oass.IndexSchema.readSchema [implicitcoll0_c_replica5] Schema name=test
   [junit4]   2> 51342 T36 oass.IndexSchema.readSchema [implicitcoll0_a_replica5] Schema name=test
   [junit4]   2> 51624 T70 oass.IndexSchema.readSchema [implicitcoll0_b_replica2] Schema name=test
   [junit4]   2> 51902 T55 oass.IndexSchema.readSchema [implicitcoll0_b_replica3] Schema name=test
   [junit4]   2> 51958 T98 oass.IndexSchema.readSchema [implicitcoll0_a_replica1] Schema name=test
   [junit4]   2> 51966 T83 oass.IndexSchema.readSchema [implicitcoll0_c_replica4] Schema name=test
   [junit4]   2> 52177 T67 oass.IndexSchema.readSchema [implicitcoll0_a_replica2] Schema name=test
   [junit4]   2> 52298 T99 oass.IndexSchema.readSchema [implicitcoll0_b_replica1] Schema name=test
   [junit4]   2> 66544 T54 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 66725 T35 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 66740 T84 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 66821 T84 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 66867 T35 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 66895 T54 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 66901 T54 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 66908 T84 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 67093 T35 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 67370 T54 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 67462 T84 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 67615 T84 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 67623 T35 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 67701 T54 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 67724 T35 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 67761 T35 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 67795 T84 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 67805 T54 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 67809 T84 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 67845 T84 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 67858 T84 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 67870 T38 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 67875 T67 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 67822 T54 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 67883 T54 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 67884 T54 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 67858 T35 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 67907 T35 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 67908 T35 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 67917 T84 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 67918 T84 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 67919 T84 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 67920 T84 oasc.SolrCore.<init> [implicitcoll0_a_replica4] Opening new SolrCore at ./org.apache.solr.cloud.CustomCollectionTest-jetty3-1382362671321/implicitcoll0_a_replica4/, dataDir=./org.apache.solr.cloud.CustomCollectionTest-jetty3-1382362671321/implicitcoll0_a_replica4/data/
   [junit4]   2> 67930 T54 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 67932 T54 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 67933 T54 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 67935 T54 oasc.SolrCore.<init> [implicitcoll0_a_replica3] Opening new SolrCore at ./org.apache.solr.cloud.CustomCollectionTest-jetty1-1382362667264/implicitcoll0_a_replica3/, dataDir=./org.apache.solr.cloud.CustomCollectionTest-jetty1-1382362667264/implicitcoll0_a_replica3/data/
   [junit4]   2> 67941 T35 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 67942 T35 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 67943 T35 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 67944 T35 oasc.SolrCore.<init> [implicitcoll0_b_replica5] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-controljetty-1382362664309/implicitcoll0_b_replica5/, dataDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CustomCollectionTest-controljetty-1382362664309/implicitcoll0_b_replica5/data/
   [junit4]   2> 68050 T100 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 68094 T99 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 68145 T67 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 68282 T35 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@52e29c38
   [junit4]   2> 68241 T84 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@52e29c38
   [junit4]   2> 68206 T38 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 68178 T54 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@52e29c38
   [junit4]   2> 68334 T100 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 68336 T84 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CustomCollectionTest-jetty3-1382362671321/implicitcoll0_a_replica4/data
   [junit4]   2> 68337 T54 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CustomCollectionTest-jetty1-1382362667264/implicitcoll0_a_replica3/data
   [junit4]   2> 68338 T84 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CustomCollectionTest-jetty3-1382362671321/implicitcoll0_a_replica4/data/index/
   [junit4]   2> 68340 T84 oasc.SolrCore.initIndex WARN [implicitcoll0_a_replica4] Solr index directory './org.apache.solr.cloud.CustomCollectionTe

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

e.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 207292 T21 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 207294 T21 oasc.SolrCore.closeSearcher [implicitcoll0_c_replica1] Closing main searcher on request.
   [junit4]   2> 207295 T21 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 207296 T21 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.CustomCollectionTest-jetty4-1382362673320/implicitcoll0_c_replica1/data/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.CustomCollectionTest-jetty4-1382362673320/implicitcoll0_c_replica1/data/index;done=false>>]
   [junit4]   2> 207297 T21 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.CustomCollectionTest-jetty4-1382362673320/implicitcoll0_c_replica1/data/index
   [junit4]   2> 207297 T21 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.CustomCollectionTest-jetty4-1382362673320/implicitcoll0_c_replica1/data [CachedDir<<refCount=0;path=./org.apache.solr.cloud.CustomCollectionTest-jetty4-1382362673320/implicitcoll0_c_replica1/data;done=false>>]
   [junit4]   2> 207298 T21 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.CustomCollectionTest-jetty4-1382362673320/implicitcoll0_c_replica1/data
   [junit4]   2> 207298 T21 oasc.SolrCore.close [implicitcoll0_a_replica1]  CLOSING SolrCore org.apache.solr.core.SolrCore@2c0c7e73
   [junit4]   2> 207320 T21 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=3,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
   [junit4]   2> 207321 T21 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 207321 T21 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 207322 T21 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 207324 T21 oasc.SolrCore.closeSearcher [implicitcoll0_a_replica1] Closing main searcher on request.
   [junit4]   2> 207325 T21 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 207326 T21 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.CustomCollectionTest-jetty4-1382362673320/implicitcoll0_a_replica1/data [CachedDir<<refCount=0;path=./org.apache.solr.cloud.CustomCollectionTest-jetty4-1382362673320/implicitcoll0_a_replica1/data;done=false>>]
   [junit4]   2> 207327 T21 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.CustomCollectionTest-jetty4-1382362673320/implicitcoll0_a_replica1/data
   [junit4]   2> 207327 T21 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.CustomCollectionTest-jetty4-1382362673320/implicitcoll0_a_replica1/data/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.CustomCollectionTest-jetty4-1382362673320/implicitcoll0_a_replica1/data/index;done=false>>]
   [junit4]   2> 207328 T21 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.CustomCollectionTest-jetty4-1382362673320/implicitcoll0_a_replica1/data/index
   [junit4]   2> 207329 T21 oasc.SolrCore.close [implicitcoll0_b_replica1]  CLOSING SolrCore org.apache.solr.core.SolrCore@3c0c91d7
   [junit4]   2> 207357 T21 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
   [junit4]   2> 207358 T21 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 207359 T21 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 207359 T21 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 207362 T21 oasc.SolrCore.closeSearcher [implicitcoll0_b_replica1] Closing main searcher on request.
   [junit4]   2> 207363 T21 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 207363 T21 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.CustomCollectionTest-jetty4-1382362673320/implicitcoll0_b_replica1/data [CachedDir<<refCount=0;path=./org.apache.solr.cloud.CustomCollectionTest-jetty4-1382362673320/implicitcoll0_b_replica1/data;done=false>>]
   [junit4]   2> 207364 T21 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.CustomCollectionTest-jetty4-1382362673320/implicitcoll0_b_replica1/data
   [junit4]   2> 207364 T21 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.CustomCollectionTest-jetty4-1382362673320/implicitcoll0_b_replica1/data/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.CustomCollectionTest-jetty4-1382362673320/implicitcoll0_b_replica1/data/index;done=false>>]
   [junit4]   2> 207365 T21 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.CustomCollectionTest-jetty4-1382362673320/implicitcoll0_b_replica1/data/index
   [junit4]   2> 207366 T193 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=90594519421091852-127.0.0.1:49172_fm%2Fc-n_0000000004) am no longer a leader.
   [junit4]   2> 207390 T21 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/fm/c,null}
   [junit4]   2> 207451 T21 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
   [junit4]   2> 207457 T21 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:49155 49155
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=CustomCollectionTest -Dtests.method=testDistribSearch -Dtests.seed=BFE5884AFE79729B -Dtests.slow=true -Dtests.locale=es_EC -Dtests.timezone=Etc/GMT+5 -Dtests.file.encoding=UTF-8
   [junit4] ERROR    182s | CustomCollectionTest.testDistribSearch <<<
   [junit4]    > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: collection already exists: implicitcoll0
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([BFE5884AFE79729B:3E030652892612A7]:0)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:464)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:268)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:636)
   [junit4]    > 	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1580)
   [junit4]    > 	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1542)
   [junit4]    > 	at org.apache.solr.cloud.CustomCollectionTest.testCustomCollectionsAPI(CustomCollectionTest.java:190)
   [junit4]    > 	at org.apache.solr.cloud.CustomCollectionTest.doTest(CustomCollectionTest.java:133)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 207623 T21 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 181925 T20 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
   [junit4]   2> 208874 T104 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> NOTE: test params are: codec=FastDecompressionCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=FAST_DECOMPRESSION, chunkSize=381), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=FAST_DECOMPRESSION, chunkSize=381)), sim=RandomSimilarityProvider(queryNorm=true,coord=no): {}, locale=es_EC, timezone=Etc/GMT+5
   [junit4]   2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.7.0_45 (64-bit)/cpus=2,threads=1,free=37001208,total=130646016
   [junit4]   2> NOTE: All tests run in this JVM: [DirectSolrConnectionTest, WordBreakSolrSpellCheckerTest, CustomCollectionTest]
   [junit4] Completed in 183.31s, 1 test, 1 error <<< FAILURES!

[...truncated 1004 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:422: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:402: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:39: 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:483: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:1259: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:902: There were test failures: 326 suites, 1449 tests, 1 error, 40 ignored (5 assumptions)

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