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/24 04:29:16 UTC

[JENKINS] Lucene-Solr-trunk-Windows (64bit/jdk1.7.0_45) - Build # 3385 - Still Failing!

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

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

Error Message:
collection already exists: implicitcollwithShardField

Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: collection already exists: implicitcollwithShardField
	at __randomizedtesting.SeedInfo.seed([10D863DDBB5B7E92:913EEDC5CC041EAE]: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:640)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1598)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1560)
	at org.apache.solr.cloud.CustomCollectionTest.testCustomCollectionsAPI(CustomCollectionTest.java:319)
	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 10194 lines...]
   [junit4] Suite: org.apache.solr.cloud.CustomCollectionTest
   [junit4]   2> 1369930 T3059 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 1369937 T3059 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-CustomCollectionTest-1382579472838
   [junit4]   2> 1369939 T3059 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 1369939 T3060 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1370039 T3059 oasc.ZkTestServer.run start zk server on port:64331
   [junit4]   2> 1370043 T3059 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1370054 T3066 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@45befdf8 name:ZooKeeperConnection Watcher:127.0.0.1:64331 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1370055 T3059 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1370055 T3059 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1370066 T3061 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x141e82889ce0000, 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> 1370068 T3059 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1370073 T3068 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7ce8a5d5 name:ZooKeeperConnection Watcher:127.0.0.1:64331/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1370074 T3059 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1370074 T3059 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 1370081 T3059 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 1370085 T3059 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 1370089 T3059 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 1370093 T3059 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 1370093 T3059 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 1370100 T3059 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 1370101 T3059 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 1370106 T3059 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1370107 T3059 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1370115 T3059 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 1370116 T3059 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 1370121 T3059 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 1370122 T3059 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 1370128 T3059 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 1370129 T3059 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 1370133 T3059 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1370134 T3059 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1370138 T3059 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1370138 T3059 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1370143 T3059 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 1370143 T3059 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 1370147 T3059 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 1370159 T3059 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 1370608 T3059 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1370616 T3059 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:64338
   [junit4]   2> 1370616 T3059 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1370617 T3059 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1370617 T3059 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\org.apache.solr.cloud.CustomCollectionTest-controljetty-1382579473065
   [junit4]   2> 1370617 T3059 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.cloud.CustomCollectionTest-controljetty-1382579473065\'
   [junit4]   2> 1370651 T3059 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-controljetty-1382579473065\solr.xml
   [junit4]   2> 1370773 T3059 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 1370775 T3059 oasc.CoreContainer.<init> New CoreContainer 279228228
   [junit4]   2> 1370775 T3059 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\org.apache.solr.cloud.CustomCollectionTest-controljetty-1382579473065\]
   [junit4]   2> 1370777 T3059 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1370777 T3059 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1370777 T3059 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1370778 T3059 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1370778 T3059 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1370779 T3059 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1370779 T3059 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1370779 T3059 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1370779 T3059 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1370783 T3059 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1370784 T3059 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1370784 T3059 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:64331/solr
   [junit4]   2> 1370785 T3059 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1370787 T3059 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1370793 T3079 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1789a603 name:ZooKeeperConnection Watcher:127.0.0.1:64331 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1370794 T3059 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1370799 T3059 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1370802 T3081 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2d991a8a name:ZooKeeperConnection Watcher:127.0.0.1:64331/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1370802 T3059 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1370805 T3059 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1370810 T3059 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1370815 T3059 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1370817 T3059 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:64338_
   [junit4]   2> 1370819 T3059 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:64338_
   [junit4]   2> 1370824 T3059 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1370830 T3059 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1370833 T3059 oasc.Overseer.start Overseer (id=90608728332435459-127.0.0.1:64338_-n_0000000000) starting
   [junit4]   2> 1370839 T3059 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1370845 T3083 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1370846 T3059 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1370850 T3059 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1370852 T3059 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1370857 T3082 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1370861 T3059 oasc.CorePropertiesLocator.discover Looking for core definitions underneath C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-controljetty-1382579473065
   [junit4]   2> 1371114 T3059 oasc.CorePropertiesLocator.discoverUnder Found core conf in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-controljetty-1382579473065\conf\
   [junit4]   2> 1371128 T3059 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 1371129 T3059 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 1371129 T3059 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1371135 T3059 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1371138 T3086 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5afb5b9 name:ZooKeeperConnection Watcher:127.0.0.1:64331/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1371138 T3059 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1371140 T3059 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1371144 T3059 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
   [junit4]   2> 1371599 T3059 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1371603 T3059 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:64350
   [junit4]   2> 1371604 T3059 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1371604 T3059 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1371604 T3059 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty1-1382579474044
   [junit4]   2> 1371605 T3059 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty1-1382579474044\'
   [junit4]   2> 1371649 T3059 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty1-1382579474044\solr.xml
   [junit4]   2> 1371764 T3059 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 1371765 T3059 oasc.CoreContainer.<init> New CoreContainer 1435746676
   [junit4]   2> 1371765 T3059 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty1-1382579474044\]
   [junit4]   2> 1371767 T3059 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1371767 T3059 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1371768 T3059 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1371768 T3059 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1371768 T3059 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1371769 T3059 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1371769 T3059 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1371769 T3059 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1371770 T3059 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1371773 T3059 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1371774 T3059 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1371774 T3059 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:64331/solr
   [junit4]   2> 1371774 T3059 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1371776 T3059 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1371796 T3097 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5ace8939 name:ZooKeeperConnection Watcher:127.0.0.1:64331 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1371797 T3059 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1371800 T3061 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x141e82889ce0005, 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> 1371805 T3059 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1371808 T3099 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@21c6f319 name:ZooKeeperConnection Watcher:127.0.0.1:64331/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1371808 T3059 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1371816 T3059 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1372822 T3059 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:64350_
   [junit4]   2> 1372825 T3059 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:64350_
   [junit4]   2> 1372844 T3086 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1372845 T3099 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1372845 T3081 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1372854 T3059 oasc.CorePropertiesLocator.discover Looking for core definitions underneath C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty1-1382579474044
   [junit4]   2> 1373094 T3059 oasc.CorePropertiesLocator.discoverUnder Found core conf in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty1-1382579474044\conf\
   [junit4]   2> 1373107 T3059 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 1373108 T3059 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 1373108 T3059 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1373592 T3059 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1373597 T3059 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:64359
   [junit4]   2> 1373597 T3059 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1373598 T3059 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1373598 T3059 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty2-1382579476012
   [junit4]   2> 1373599 T3059 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty2-1382579476012\'
   [junit4]   2> 1373632 T3059 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty2-1382579476012\solr.xml
   [junit4]   2> 1373745 T3059 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 1373745 T3059 oasc.CoreContainer.<init> New CoreContainer 560076406
   [junit4]   2> 1373745 T3059 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty2-1382579476012\]
   [junit4]   2> 1373759 T3059 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1373759 T3059 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1373760 T3059 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1373760 T3059 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1373760 T3059 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1373760 T3059 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1373760 T3059 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1373762 T3059 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1373762 T3059 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1373765 T3059 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1373765 T3059 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1373766 T3059 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:64331/solr
   [junit4]   2> 1373766 T3059 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1373769 T3059 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1373782 T3111 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3fe2e169 name:ZooKeeperConnection Watcher:127.0.0.1:64331 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1373783 T3059 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1373790 T3061 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x141e82889ce0007, 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> 1373792 T3059 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1373796 T3113 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3ba13dea name:ZooKeeperConnection Watcher:127.0.0.1:64331/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1373796 T3059 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1373807 T3059 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1374814 T3059 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:64359_
   [junit4]   2> 1374818 T3059 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:64359_
   [junit4]   2> 1374828 T3086 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1374828 T3113 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1374828 T3081 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1374829 T3099 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1374838 T3059 oasc.CorePropertiesLocator.discover Looking for core definitions underneath C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty2-1382579476012
   [junit4]   2> 1375095 T3059 oasc.CorePropertiesLocator.discoverUnder Found core conf in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty2-1382579476012\conf\
   [junit4]   2> 1375109 T3059 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 1375110 T3059 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 1375110 T3059 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1375573 T3059 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1375577 T3059 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:64368
   [junit4]   2> 1375578 T3059 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1375578 T3059 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1375578 T3059 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty3-1382579478014
   [junit4]   2> 1375578 T3059 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty3-1382579478014\'
   [junit4]   2> 1375613 T3059 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty3-1382579478014\solr.xml
   [junit4]   2> 1375744 T3059 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 1375744 T3059 oasc.CoreContainer.<init> New CoreContainer 753989804
   [junit4]   2> 1375745 T3059 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty3-1382579478014\]
   [junit4]   2> 1375746 T3059 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1375746 T3059 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1375746 T3059 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1375746 T3059 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1375746 T3059 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1375747 T3059 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1375747 T3059 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1375748 T3059 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1375748 T3059 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1375752 T3059 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1375752 T3059 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1375752 T3059 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:64331/solr
   [junit4]   2> 1375752 T3059 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1375755 T3059 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1375759 T3125 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@643f9180 name:ZooKeeperConnection Watcher:127.0.0.1:64331 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1375760 T3059 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1375763 T3061 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x141e82889ce0009, 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> 1375766 T3059 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1375769 T3127 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@79cc1b34 name:ZooKeeperConnection Watcher:127.0.0.1:64331/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1375769 T3059 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1375776 T3059 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1376783 T3059 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:64368_
   [junit4]   2> 1376786 T3059 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:64368_
   [junit4]   2> 1376796 T3099 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1376797 T3081 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1376798 T3127 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1376799 T3086 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1376801 T3113 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1376813 T3059 oasc.CorePropertiesLocator.discover Looking for core definitions underneath C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty3-1382579478014
   [junit4]   2> 1377061 T3059 oasc.CorePropertiesLocator.discoverUnder Found core conf in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty3-1382579478014\conf\
   [junit4]   2> 1377073 T3059 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 1377074 T3059 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 1377074 T3059 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1377495 T3059 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1377498 T3059 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:64377
   [junit4]   2> 1377500 T3059 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1377500 T3059 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1377500 T3059 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty4-1382579479978
   [junit4]   2> 1377500 T3059 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty4-1382579479978\'
   [junit4]   2> 1377535 T3059 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty4-1382579479978\solr.xml
   [junit4]   2> 1377662 T3059 oasc.ConfigSolrXml.<init> Config-defined core root directory: 
   [junit4]   2> 1377662 T3059 oasc.CoreContainer.<init> New CoreContainer 1306569585
   [junit4]   2> 1377662 T3059 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty4-1382579479978\]
   [junit4]   2> 1377664 T3059 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1377664 T3059 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1377664 T3059 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1377665 T3059 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1377665 T3059 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1377665 T3059 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1377666 T3059 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1377666 T3059 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1377666 T3059 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1377670 T3059 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1377670 T3059 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1377671 T3059 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:64331/solr
   [junit4]   2> 1377671 T3059 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1377673 T3059 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1377703 T3139 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f407fbd name:ZooKeeperConnection Watcher:127.0.0.1:64331 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1377704 T3059 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1377712 T3059 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1377718 T3141 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@63e24888 name:ZooKeeperConnection Watcher:127.0.0.1:64331/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1377719 T3059 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1377733 T3059 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1378739 T3059 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:64377_
   [junit4]   2> 1378742 T3059 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:64377_
   [junit4]   2> 1378748 T3113 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1378749 T3141 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1378749 T3127 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1378749 T3081 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1378750 T3099 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1378750 T3086 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1378758 T3059 oasc.CorePropertiesLocator.discover Looking for core definitions underneath C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty4-1382579479978
   [junit4]   2> 1378989 T3059 oasc.CorePropertiesLocator.discoverUnder Found core conf in C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty4-1382579479978\conf\
   [junit4]   2> 1378999 T3059 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 1379000 T3059 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 1379001 T3059 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1379007 T3059 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1379010 T3144 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@cc6fd0a name:ZooKeeperConnection Watcher:127.0.0.1:64331/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1379010 T3059 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1379012 T3059 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1379018 T3059 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1379021 T3146 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6acc0694 name:ZooKeeperConnection Watcher:127.0.0.1:64331/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1379021 T3059 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1379023 T3059 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1379028 T3123 oasha.CollectionsHandler.handleCreateAction Creating Collection : shards=a,b,c&maxShardsPerNode=3&name=implicitcoll0&replicationFactor=3&action=CREATE&wt=javabin&router.name=implicit&version=2
   [junit4]   2> 1379030 T3081 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1379034 T3083 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":"3",
   [junit4]   2> 	  "name":"implicitcoll0",
   [junit4]   2> 	  "replicationFactor":"3",
   [junit4]   2> 	  "router.name":"implicit"}
   [junit4]   2> 1379034 T3083 oasc.OverseerCollectionProcessor.processMessage WARN OverseerCollectionProcessor.processMessage : createcollection , {
   [junit4]   2> 	  "operation":"createcollection",
   [junit4]   2> 	  "shards":"a,b,c",
   [junit4]   2> 	  "maxShardsPerNode":"3",
   [junit4]   2> 	  "name":"implicitcoll0",
   [junit4]   2> 	  "replicationFactor":"3",
   [junit4]   2> 	  "router.name":"implicit"}
   [junit4]   2> 1379882 T3082 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1379885 T3082 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: implicitcoll0
   [junit4]   2> 1379885 T3082 oasc.Overseer$ClusterStateUpdater.createCollection Create collection implicitcoll0 with shards [a, b, c]
   [junit4]   2> 1379900 T3146 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> 1379900 T3086 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> 1379906 T3099 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> 1379907 T3141 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> 1379906 T3113 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> 1379909 T3127 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> 1379910 T3081 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> 1379911 T3144 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> 1379946 T3083 oasc.OverseerCollectionProcessor.createCollection going to create cores replicas shardNames [a, b, c] , repFactor : 3
   [junit4]   2> 1379946 T3083 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_a_replica1 as part of slice a of collection implicitcoll0 on 127.0.0.1:64350_
   [junit4]   2> 1379947 T3083 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_a_replica2 as part of slice a of collection implicitcoll0 on 127.0.0.1:64338_
   [junit4]   2> 1379949 T3083 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_a_replica3 as part of slice a of collection implicitcoll0 on 127.0.0.1:64368_
   [junit4]   2> 1379952 T3083 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_b_replica1 as part of slice b of collection implicitcoll0 on 127.0.0.1:64377_
   [junit4]   2> 1379961 T3091 oasc.ZkController.publish publishing core=implicitcoll0_a_replica1 state=down
   [junit4]   2> 1379961 T3083 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_b_replica2 as part of slice b of collection implicitcoll0 on 127.0.0.1:64359_
   [junit4]   2> 1379961 T3083 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_b_replica3 as part of slice b of collection implicitcoll0 on 127.0.0.1:64350_
   [junit4]   2> 1379962 T3083 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_c_replica1 as part of slice c of collection implicitcoll0 on 127.0.0.1:64338_
   [junit4]   2> 1379963 T3074 oasc.ZkController.publish publishing core=implicitcoll0_a_replica2 state=down
   [junit4]   2> 1379965 T3083 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_c_replica2 as part of slice c of collection implicitcoll0 on 127.0.0.1:64368_
   [junit4]   2> 1379968 T3083 oasc.OverseerCollectionProcessor.createCollection Creating shard implicitcoll0_c_replica3 as part of slice c of collection implicitcoll0 on 127.0.0.1:64377_
   [junit4]   2> 1379976 T3075 oasc.ZkController.publish publishing core=implicitcoll0_c_replica1 state=down
   [junit4]   2> 1379975 T3109 oasc.ZkController.publish publishing core=implicitcoll0_b_replica2 state=down
   [junit4]   2> 1379973 T3091 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1379973 T3119 oasc.ZkController.publish publishing core=implicitcoll0_a_replica3 state=down
   [junit4]   2> 1379980 T3074 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1379981 T3121 oasc.ZkController.publish publishing core=implicitcoll0_c_replica2 state=down
   [junit4]   2> 1379982 T3092 oasc.ZkController.publish publishing core=implicitcoll0_b_replica3 state=down
   [junit4]   2> 1379983 T3136 oasc.ZkController.publish publishing core=implicitcoll0_b_replica1 state=down
   [junit4]   2> 1379985 T3075 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1379986 T3119 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1379986 T3121 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1379987 T3092 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1379986 T3109 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1379987 T3136 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1379988 T3137 oasc.ZkController.publish publishing core=implicitcoll0_c_replica3 state=down
   [junit4]   2> 1379990 T3137 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1381427 T3082 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1381430 T3082 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:64350",
   [junit4]   2> 	  "core":"implicitcoll0_a_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:64350_",
   [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> 1381438 T3082 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:64338",
   [junit4]   2> 	  "core":"implicitcoll0_a_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:64338_",
   [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_node2"}
   [junit4]   2> 1381445 T3082 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:64338",
   [junit4]   2> 	  "core":"implicitcoll0_c_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:64338_",
   [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_node3"}
   [junit4]   2> 1381452 T3082 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:64359",
   [junit4]   2> 	  "core":"implicitcoll0_b_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:64359_",
   [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_node4"}
   [junit4]   2> 1381458 T3082 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:64368",
   [junit4]   2> 	  "core":"implicitcoll0_a_replica3",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:64368_",
   [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> 1381465 T3082 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:64368",
   [junit4]   2> 	  "core":"implicitcoll0_c_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:64368_",
   [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_node6"}
   [junit4]   2> 1381472 T3082 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:64350",
   [junit4]   2> 	  "core":"implicitcoll0_b_replica3",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:64350_",
   [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> 1381479 T3082 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:64377",
   [junit4]   2> 	  "core":"implicitcoll0_b_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:64377_",
   [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_node8"}
   [junit4]   2> 1381487 T3082 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:64377",
   [junit4]   2> 	  "core":"implicitcoll0_c_replica3",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:64377_",
   [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_node9"}
   [junit4]   2> 1381510 T3146 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> 1381511 T3086 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> 1381511 T3144 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> 1381512 T3081 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> 1381512 T3141 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> 1381512 T3127 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> 1381513 T3099 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> 1381513 T3113 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> 1381979 T3091 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_a_replica1
   [junit4]   2> 1381980 T3074 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_a_replica2
   [junit4]   2> 1381984 T3091 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_a_replica1' using instanceDir: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty1-1382579474044\implicitcoll0_a_replica1
   [junit4]   2> 1381986 T3075 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_c_replica1
   [junit4]   2> 1381986 T3119 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_a_replica3
   [junit4]   2> 1381988 T3092 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_b_replica3
   [junit4]   2> 1381990 T3075 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_c_replica1' using instanceDir: .\org.apache.solr.cloud.CustomCollectionTest-controljetty-1382579473065\implicitcoll0_c_replica1
   [junit4]   2> 1381990 T3075 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
   [junit4]   2> 1381993 T3092 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_b_replica3' using instanceDir: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty1-1382579474044\implicitcoll0_b_replica3
   [junit4]   2> 1381993 T3092 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
   [junit4]   2> 1381986 T3091 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
   [junit4]   2> 1381985 T3074 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_a_replica2' using instanceDir: .\org.apache.solr.cloud.CustomCollectionTest-controljetty-1382579473065\implicitcoll0_a_replica2
   [junit4]   2> 1381997 T3074 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
   [junit4]   2> 1381996 T3137 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_c_replica3
   [junit4]   2> 1381996 T3109 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_b_replica2
   [junit4]   2> 1381996 T3121 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_c_replica2
   [junit4]   2> 1381995 T3136 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for implicitcoll0_b_replica1
   [junit4]   2> 1381995 T3075 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:implicitcoll0
   [junit4]   2> 1382000 T3075 oasc.ZkController.getConfName Looking for collection configName
   [junit4]   2> 1381994 T3119 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_a_replica3' using instanceDir: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty3-1382579478014\implicitcoll0_a_replica3
   [junit4]   2> 1382001 T3119 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
   [junit4]   2> 1382000 T3074 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:implicitcoll0
   [junit4]   2> 1382002 T3109 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_b_replica2' using instanceDir: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty2-1382579476012\implicitcoll0_b_replica2
   [junit4]   2> 1382002 T3109 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
   [junit4]   2> 1382003 T3136 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_b_replica1' using instanceDir: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty4-1382579479978\implicitcoll0_b_replica1
   [junit4]   2> 1382003 T3136 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
   [junit4]   2> 1382004 T3137 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_c_replica3' using instanceDir: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty4-1382579479978\implicitcoll0_c_replica3
   [junit4]   2> 1382005 T3137 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
   [junit4]   2> 1381997 T3092 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:implicitcoll0
   [junit4]   2> 1382006 T3092 oasc.ZkController.getConfName Looking for collection configName
   [junit4]   2> 1382007 T3121 oasc.CoreContainer.create Creating SolrCore 'implicitcoll0_c_replica2' using instanceDir: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty3-1382579478014\implicitcoll0_c_replica2
   [junit4]   2> 1382007 T3121 oasc.ZkController.createCollectionZkNode Check for collection zkNode:implicitcoll0
   [junit4]   2> 1382009 T3136 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:implicitcoll0
   [junit4]   2> 1382010 T3136 oasc.ZkController.getConfName Looking for collection configName
   [junit4]   2> 1382011 T3075 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
   [junit4]   2> 1382011 T3075 oascc.SolrZkClient.makePath makePath: /collections/implicitcoll0
   [junit4]   2> 1381997 T3091 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:implicitcoll0
   [junit4]   2> 1382013 T3091 oasc.ZkController.getConfName Looking for collection configName
   [junit4]   2> 1382002 T3074 oasc.ZkController.getConfName Looking for collection configName
   [junit4]   2> 1382014 T3119 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:implicitcoll0
   [junit4]   2> 1382015 T3119 oasc.ZkController.getConfName Looking for collection configName
   [junit4]   2> 1382014 T3121 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:implicitcoll0
   [junit4]   2> 1382016 T3121 oasc.ZkController.getConfName Looking for collection configName
   [junit4]   2> 1382014 T3137 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:implicitcoll0
   [junit4]   2> 1382016 T3137 oasc.ZkController.getConfName Looking for collection configName
   [junit4]   2> 1382017 T3136 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
   [junit4]   2> 1382018 T3136 oascc.SolrZkClient.makePath makePath: /collections/implicitcoll0
   [junit4]   2> 1382014 T3109 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:implicitcoll0
   [junit4]   2> 1382016 T3092 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
   [junit4]   2> 1382019 T3091 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
   [junit4]   2> 1382020 T3091 oascc.SolrZkClient.makePath makePath: /collections/implicitcoll0
   [junit4]   2> 1382019 T3092 oascc.SolrZkClient.makePath makePath: /collections/implicitcoll0
   [junit4]   2> 1382019 T3109 oasc.ZkController.getConfName Looking for collection configName
   [junit4]   2> 1382023 T3119 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
   [junit4]   2> 1382023 T3119 oascc.SolrZkClient.makePath makePath: /collections/implicitcoll0
   [junit4]   2> 1382023 T3121 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
   [junit4]   2> 1382023 T3121 oascc.SolrZkClient.makePath makePath: /collections/implicitcoll0
   [junit4]   2> 1382024 T3137 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
   [junit4]   2> 1382024 T3137 oascc.SolrZkClient.makePath makePath: /collections/implicitcoll0
   [junit4]   2> 1382022 T3074 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
   [junit4]   2> 1382025 T3074 oascc.SolrZkClient.makePath makePath: /collections/implicitcoll0
   [junit4]   2> 1382026 T3075 oasc.ZkController.readConfigName Load collection config from:/collections/implicitcoll0
   [junit4]   2> 1382027 T3136 oasc.ZkController.readConfigName Load collection config from:/collections/implicitcoll0
   [junit4]   2> 1382031 T3075 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.cloud.CustomCollectionTest-controljetty-1382579473065\implicitcoll0_c_replica1\'
   [junit4]   2> 1382032 T3136 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty4-1382579479978\implicitcoll0_b_replica1\'
   [junit4]   2> 1382036 T3109 oascc.SolrZkClient.makePath makePath: /collections/implicitcoll0
   [junit4]   2> 1382037 T3092 oasc.ZkController.readConfigName Load collection config from:/collections/implicitcoll0
   [junit4]   2> 1382039 T3074 oasc.ZkController.readConfigName Load collection config from:/collections/implicitcoll0
   [junit4]   2> 1382051 T3091 oasc.ZkController.readConfigName Load collection config from:/collections/implicitcoll0
   [junit4]   2> 1382054 T3121 oasc.ZkController.readConfigName Load collection config from:/collections/implicitcoll0
   [junit4]   2> 1382055 T3119 oasc.ZkController.readConfigName Load collection config from:/collections/implicitcoll0
   [junit4]   2> 1382056 T3137 oasc.ZkController.readConfigName Load collection config from:/collections/implicitcoll0
   [junit4]   2> 1382058 T3074 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.cloud.CustomCollectionTest-controljetty-1382579473065\implicitcoll0_a_replica2\'
   [junit4]   2> 1382059 T3091 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty1-1382579474044\implicitcoll0_a_replica1\'
   [junit4]   2> 1382061 T3109 oasc.ZkController.readConfigName Load collection config from:/collections/implicitcoll0
   [junit4]   2> 1382063 T3092 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty1-1382579474044\implicitcoll0_b_replica3\'
   [junit4]   2> 1382064 T3121 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty3-1382579478014\implicitcoll0_c_replica2\'
   [junit4]   2> 1382065 T3119 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty3-1382579478014\implicitcoll0_a_replica3\'
   [junit4]   2> 1382066 T3137 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty4-1382579479978\implicitcoll0_c_replica3\'
   [junit4]   2> 1382092 T3109 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty2-1382579476012\implicitcoll0_b_replica2\'
   [junit4]   2> 1382258 T3075 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 1382281 T3074 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 1382493 T3074 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1382549 T3091 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 1382554 T3074 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1382549 T3121 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 1382577 T3074 oass.IndexSchema.readSchema [implicitcoll0_a_replica2] Schema name=test
   [junit4]   2> 1382708 T3136 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 1382839 T3075 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1383071 T3075 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1383108 T3075 oass.IndexSchema.readSchema [implicitcoll0_c_replica1] Schema name=test
   [junit4]   2> 1383137 T3109 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 1383305 T3091 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1383343 T3091 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1383353 T3091 oass.IndexSchema.readSchema [implicitcoll0_a_replica1] Schema name=test
   [junit4]   2> 1383354 T3121 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1383444 T3092 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 1383459 T3121 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1383469 T3121 oass.IndexSchema.readSchema [implicitcoll0_c_replica2] Schema name=test
   [junit4]   2> 1383509 T3136 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1383510 T3119 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 1383636 T3136 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1383687 T3136 oass.IndexSchema.readSchema [implicitcoll0_b_replica1] Schema name=test
   [junit4]   2> 1383795 T3137 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 1384187 T3109 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1384332 T3109 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1384503 T3119 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1384572 T3137 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1384618 T3119 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1384647 T3137 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1384658 T3109 oass.IndexSchema.readSchema [implicitcoll0_b_replica2] Schema name=test
   [junit4]   2> 1384770 T3119 oass.IndexSchema.readSchema [implicitcoll0_a_replica3] Schema name=test
   [junit4]   2> 1384811 T3137 oass.IndexSchema.readSchema [implicitcoll0_c_replica3] Schema name=test
   [junit4]   2> 1384862 T3092 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1384931 T3092 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1384942 T3092 oass.IndexSchema.readSchema [implicitcoll0_b_replica3] Schema name=test
   [junit4]   2> 1388362 T3074 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1388439 T3074 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1388444 T3074 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1389370 T3074 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1389510 T3074 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1389662 T3074 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1389691 T3136 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1389768 T3074 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1389769 T3074 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1389769 T3074 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1389777 T3136 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1389781 T3136 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1389925 T3074 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1389925 T3074 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1389925 T3074 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1389927 T3074 oasc.SolrCore.<init> [implicitcoll0_a_replica2] Opening new SolrCore at .\org.apache.solr.cloud.CustomCollectionTest-controljetty-1382579473065\implicitcoll0_a_replica2\, dataDir=.\org.apache.solr.cloud.CustomCollectionTest-controljetty-1382579473065\implicitcoll0_a_replica2\data\
   [junit4]   2> 1389927 T3074 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2261adb1
   [junit4]   2> 1389928 T3074 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.CustomCollectionTest-controljetty-1382579473065\implicitcoll0_a_replica2\data\
   [junit4]   2> 1389928 T3074 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.CustomCollectionTest-controljetty-1382579473065\implicitcoll0_a_replica2\data\index/
   [junit4]   2> 1389929 T3074 oasc.SolrCore.initIndex WARN [implicitcoll0_a_replica2] Solr index directory '.\org.apache.solr.cloud.CustomCollectionTest-controljetty-1382579473065\implicitcoll0_a_replica2\data\index' doesn't exist. Creating new index...
   [junit4]   2> 1389929 T3074 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.CustomCollectionTest-controljetty-1382579473065\implicitcoll0_a_replica2\data\index
   [junit4]   2> 1389930 T3074 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=21, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.3025256810092152]
   [junit4]   2> 1389931 T3074 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@30fca733 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@10f8c6ff),segFN=segments_1,generation=1}
   [junit4]   2> 1389931 T3074 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1389936 T3074 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1389938 T3074 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1389938 T3074 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1389985 T3074 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1389985 T3074 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1389986 T3074 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1389986 T3074 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1389987 T3074 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1389987 T3074 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1389988 T3074 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1389989 T3074 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1389989 T3074 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1389989 T3074 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1389990 T3074 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1389991 T3074 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1390118 T3074 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1390168 T3074 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1390168 T3074 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1390169 T3074 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=46, maxMergeAtOnceExplicit=50, maxMergedSegmentMB=76.66796875, floorSegmentMB=0.9833984375, forceMergeDeletesPctAllowed=19.053938499402456, segmentsPerTier=25.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 1390170 T3074 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@30fca733 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@10f8c6ff),segFN=segments_1,generation=1}
   [junit4]   2> 1390170 T3074 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1390195 T3074 oass.SolrIndexSearcher.<init> Opening Searcher@45603be0 main
   [junit4]   2> 1390331 T3156 oasc.SolrCore.registerSearcher [implicitcoll0_a_replica2] Registered new searcher Searcher@45603be0 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1390333 T3074 oasc.CoreContainer.registerCore registering core: implicitcoll0_a_replica2
   [junit4]   2> 1390334 T3074 oasc.ZkController.register Register replica - core:implicitcoll0_a_replica2 address:http://127.0.0.1:64338 collection:implicitcoll0 shard:a
   [junit4]   2> 1390412 T3074 oascc.SolrZkClient.makePath makePath: /collections/implicitcoll0/leader_elect/a/election
   [junit4]   2> 1391077 T3074 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard a
   [junit4]   2> 1391183 T3074 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up for shard a: total=3 found=1 timeoutin=179952
   [junit4]   2> 1391208 T3136 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1391266 T3136 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1391460 T3075 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1391483 T3136 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1391552 T3136 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1391552 T3136 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1391553 T3136 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1391580 T3075 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1391585 T3075 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1391614 T3092 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1391647 T3092 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1391670 T3092 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1391718 T3082 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1391719 T3136 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1391719 T3136 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1391720 T3136 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1391720 T3136 oasc.SolrCore.<init> [implicitcoll0_b_replica1] Opening new SolrCore at ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty4-1382579479978\implicitcoll0_b_replica1\, dataDir=..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty4-1382579479978\implicitcoll0_b_replica1\data\
   [junit4]   2> 1391720 T3136 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2261adb1
   [junit4]   2> 1391722 T3136 oasc.CachingDirectoryFactory.get return new directory for ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty4-1382579479978\implicitcoll0_b_replica1\data\
   [junit4]   2> 1391722 T3136 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty4-1382579479978\implicitcoll0_b_replica1\data\index/
   [junit4]   2> 1391722 T3136 oasc.SolrCore.initIndex WARN [implicitcoll0_b_replica1] Solr index directory '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty4-1382579479978\implicitcoll0_b_replica1\data\index' doesn't exist. Creating new index...
   [junit4]   2> 1391723 T3136 oasc.CachingDirectoryFactory.get return new directory for ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty4-1382579479978\implicitcoll0_b_replica1\data\index
   [junit4]   2> 1391723 T3136 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=21, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.3025256810092152]
   [junit4]   2> 1391724 T3136 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@36f61197 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@46dec835),segFN=segments_1,generation=1}
   [junit4]   2> 1391724 T3136 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1391730 T3136 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1391730 T3136 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1391731 T3136 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1391731 T3136 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1391731 T3136 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1391731 T3136 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1391747 T3136 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1391747 T3136 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1391747 T3136 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1391748 T3136 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1391749 T3136 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1391749 T3136 oasc.RequestHandlers.initHandlersFromConfig 

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

CustomCollectionTest-jetty4-1382579479978\implicitcollwithShardField_c_replica2\data\index [CachedDir<<refCount=0;path=..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty4-1382579479978\implicitcollwithShardField_c_replica2\data\index;done=false>>]
   [junit4]   2> 1501431 T3059 oasc.CachingDirectoryFactory.close Closing directory: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty4-1382579479978\implicitcollwithShardField_c_replica2\data\index
   [junit4]   2> 1501433 T3059 oasc.CachingDirectoryFactory.closeCacheValue looking to close ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty4-1382579479978\implicitcollwithShardField_c_replica2\data\ [CachedDir<<refCount=0;path=..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty4-1382579479978\implicitcollwithShardField_c_replica2\data\;done=false>>]
   [junit4]   2> 1501433 T3059 oasc.CachingDirectoryFactory.close Closing directory: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-jetty4-1382579479978\implicitcollwithShardField_c_replica2\data\
   [junit4]   2> 1501435 T3387 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=90608728332435468-127.0.0.1:64377_-n_0000000004) am no longer a leader.
   [junit4]   2> 1501454 T3059 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
   [junit4]   2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-1382579472837\zookeeper\server1\data\version-2\log.1 FAILED !!!!!
   [junit4]   2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-1382579472837\zookeeper\server1\data\version-2 FAILED !!!!!
   [junit4]   2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-1382579472837\zookeeper\server1\data FAILED !!!!!
   [junit4]   2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-1382579472837\zookeeper\server1 FAILED !!!!!
   [junit4]   2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-1382579472837\zookeeper FAILED !!!!!
   [junit4]   2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.CustomCollectionTest-1382579472837 FAILED !!!!!
   [junit4]   2> 1501520 T3059 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
   [junit4]   2> 1501523 T3059 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:64331 64331
   [junit4]   2> 1502941 T3141 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [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=10D863DDBB5B7E92 -Dtests.slow=true -Dtests.locale=es_CL -Dtests.timezone=America/North_Dakota/New_Salem -Dtests.file.encoding=ISO-8859-1
   [junit4] ERROR    134s | CustomCollectionTest.testDistribSearch <<<
   [junit4]    > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: collection already exists: implicitcollwithShardField
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([10D863DDBB5B7E92:913EEDC5CC041EAE]: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:640)
   [junit4]    > 	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1598)
   [junit4]    > 	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1560)
   [junit4]    > 	at org.apache.solr.cloud.CustomCollectionTest.testCustomCollectionsAPI(CustomCollectionTest.java:319)
   [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> 1503804 T3059 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: test params are: codec=Lucene40, sim=DefaultSimilarity, locale=es_CL, timezone=America/North_Dakota/New_Salem
   [junit4]   2> NOTE: Windows 7 6.1 amd64/Oracle Corporation 1.7.0_45 (64-bit)/cpus=2,threads=2,free=75719472,total=368386048
   [junit4]   2> NOTE: All tests run in this JVM: [QueryResultKeyTest, TestCSVLoader, TestFoldingMultitermQuery, TestXIncludeConfig, NotRequiredUniqueKeyTest, CoreAdminHandlerTest, IndexSchemaTest, TestBM25SimilarityFactory, TestLMDirichletSimilarityFactory, LoggingHandlerTest, TestImplicitCoreProperties, TestZkChroot, TestNumberUtils, TestPseudoReturnFields, TestFastLRUCache, HdfsUnloadDistributedZkTest, ConvertedLegacyTest, CoreAdminCreateDiscoverTest, AliasIntegrationTest, SolrCoreTest, TestRealTimeGet, BadIndexSchemaTest, DateFieldTest, TestSchemaResource, DocumentAnalysisRequestHandlerTest, SpatialFilterTest, TestCollationField, LeaderElectionIntegrationTest, TestDistributedGrouping, BasicZkTest, TestSolrXmlPersistor, TestSolrDeletionPolicy2, HardAutoCommitTest, TestConfig, TermVectorComponentTest, HdfsDirectoryTest, SignatureUpdateProcessorFactoryTest, TestAddFieldRealTimeGet, OpenCloseCoreStressTest, HdfsSyncSliceTest, DocumentBuilderTest, DirectSolrSpellCheckerTest, TestRecovery, TestStressLucene, DocValuesMissingTest, AutoCommitTest, PluginInfoTest, CacheHeaderTest, TestReplicationHandler, TestFieldResource, TestSchemaNameResource, TestRandomMergePolicy, TestClassNameShortening, IndexSchemaRuntimeFieldTest, HdfsChaosMonkeySafeLeaderTest, SolrXmlInZkTest, RequiredFieldsTest, QueryParsingTest, TestFieldCollectionResource, TestLRUCache, ReturnFieldsTest, WordBreakSolrSpellCheckerTest, RecoveryZkTest, TestStressRecovery, TestRangeQuery, PrimUtilsTest, SuggesterWFSTTest, MultiTermTest, FileBasedSpellCheckerTest, TestLuceneMatchVersion, DistributedQueryElevationComponentTest, QueryEqualityTest, TestNoOpRegenerator, TestCharFilters, TestOmitPositions, TestStressVersions, TestDocumentBuilder, SynonymTokenizerTest, TestPhraseSuggestions, EchoParamsTest, DisMaxRequestHandlerTest, SuggesterFSTTest, UpdateParamsTest, TestDocSet, LukeRequestHandlerTest, TestSolrQueryParser, FileUtilsTest, TestJmxMonitoredMap, HighlighterConfigTest, TestDynamicFieldCollectionResource, HdfsBasicDistributedZkTest, TestCollapseQParserPlugin, AddBlockUpdateTest, SyncSliceTest, TestTrie, CoreContainerCoreInitFailuresTest, CurrencyFieldOpenExchangeTest, TestInfoStreamLogging, TestIBSimilarityFactory, JSONWriterTest, TestUniqueKeyFieldResource, SolrPluginUtilsTest, DistributedTermsComponentTest, NumericFieldsTest, TestRecoveryHdfs, ClusterStateTest, UnloadDistributedZkTest, TestQuerySenderListener, BinaryUpdateRequestHandlerTest, SimpleFacetsTest, MinimalSchemaTest, TestSolrIndexConfig, DistributedSpellCheckComponentTest, XmlUpdateRequestHandlerTest, DeleteShardTest, SpellPossibilityIteratorTest, TestQuerySenderNoQuery, SortByFunctionTest, TestShardHandlerFactory, JsonLoaderTest, TestCloudManagedSchema, TestRemoteStreaming, HighlighterTest, TestSolrXml, TestReloadAndDeleteDocs, TestSolrCoreProperties, BasicFunctionalityTest, TestBinaryField, ResourceLoaderTest, SearchHandlerTest, TestAtomicUpdateErrorCases, SpellCheckCollatorTest, ExternalFileFieldSortTest, CustomCollectionTest]
   [junit4] Completed in 133.93s, 1 test, 1 error <<< FAILURES!

[...truncated 592 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:422: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:402: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build.xml:189: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\common-build.xml:483: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1259: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:902: There were test failures: 327 suites, 1451 tests, 1 error, 40 ignored (11 assumptions)

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