lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Erick Erickson <erickerick...@gmail.com>
Subject Re: [JENKINS] Lucene-Solr-4.x-MacOSX (64bit/jdk1.7.0) - Build # 475 - Still Failing!
Date Tue, 21 May 2013 17:45:40 GMT
The closer thread is there because if you just try to close transient
cores when the queue size is exceeded Solr deadlocks although I don't
quite remember where. But core.close() has some synchronization that
didn't play very nice when the CoreContainer wasn't being shut down
but cores were rapidly being closed/opened. Or perhaps it was just
that the synchronization around the list manipulation was at fault,
that was a while ago and the details have gone fuzzy.

It would be great if this wasn't needed, maybe if we're lucky the need
for this has been re-organized away with some of the other work that's
been done. As I remember, what was being flushed out of the woodwork
was assumptions that closing cores was when the container was being
shut down. There were several places in CoreContainer something like
..if (isShutdown) don't do anything..... for instance.

This can be quickly tested by commenting out that whole closer thread
stuff and calling core.close() directly where adding to the transient
core list returns true in SolrCores.allocateLazyCores(), then running
the stress test stuff.

FWIW
Erick

On Tue, May 21, 2013 at 9:19 AM, Mark Miller <markrmiller@gmail.com> wrote:
> This seems to happen a lot recently - I just tracked down an offending hang:
>
> "Thread-177" Id=532 WAITING on java.lang.Object@2dffce78
>                 at java.lang.Object.wait(Native Method)
>                 -  waiting on java.lang.Object@2dffce78
>                 at java.lang.Object.wait(Object.java:503)
>                 at org.apache.solr.core.CloserThread.run(CoreContainer.java:1232)
>
> Seems to be an issue with this new core CloserThread (I still have not yet learned why we need a CloserThread, on first blush it sounds scary) - and something the core stress test doesn't seem to be hitting.
>
> There are lots of threads stuck at that point.
>
> I'll take a look and see if I can spot something.
>
> - Mark
>
> On May 21, 2013, at 7:44 AM, Policeman Jenkins Server <jenkins@thetaphi.de> wrote:
>
>> Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-MacOSX/475/
>> Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseParallelGC
>>
>> 1 tests failed.
>> FAILED:  org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testDistribSearch
>>
>> Error Message:
>> There are still nodes recoverying - waited for 230 seconds
>>
>> Stack Trace:
>> java.lang.AssertionError: There are still nodes recoverying - waited for 230 seconds
>>       at __randomizedtesting.SeedInfo.seed([550DAA879EDCE8F5:D4EB249FE98388C9]:0)
>>       at org.junit.Assert.fail(Assert.java:93)
>>       at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:173)
>>       at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:131)
>>       at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:126)
>>       at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:512)
>>       at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:146)
>>       at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:815)
>>       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:601)
>>       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:722)
>>
>>
>>
>>
>> Build Log:
>> [...truncated 9253 lines...]
>> [junit4:junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
>> [junit4:junit4]   2> 390845 T477 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
>> [junit4:junit4]   2> 390856 T477 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
>> [junit4:junit4]   2> Creating dataDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1369134467512
>> [junit4:junit4]   2> 390860 T477 oasc.ZkTestServer.run STARTING ZK TEST SERVER
>> [junit4:junit4]   2> 390862 T478 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
>> [junit4:junit4]   2> 390965 T477 oasc.ZkTestServer.run start zk server on port:51206
>> [junit4:junit4]   2> 390970 T477 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
>> [junit4:junit4]   2> 390985 T484 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b7034b0 name:ZooKeeperConnection Watcher:127.0.0.1:51206 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
>> [junit4:junit4]   2> 390986 T477 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
>> [junit4:junit4]   2> 390986 T477 oascc.SolrZkClient.makePath makePath: /solr
>> [junit4:junit4]   2> 391006 T477 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
>> [junit4:junit4]   2> 391015 T486 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@34ba3669 name:ZooKeeperConnection Watcher:127.0.0.1:51206/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
>> [junit4:junit4]   2> 391016 T477 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
>> [junit4:junit4]   2> 391017 T477 oascc.SolrZkClient.makePath makePath: /collections/collection1
>> [junit4:junit4]   2> 391044 T477 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
>> [junit4:junit4]   2> 391062 T477 oascc.SolrZkClient.makePath makePath: /collections/control_collection
>> [junit4:junit4]   2> 391074 T477 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
>> [junit4:junit4]   2> 391173 T477 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
>> [junit4:junit4]   2> 391174 T477 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
>> [junit4:junit4]   2> 391190 T477 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
>> [junit4:junit4]   2> 391191 T477 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
>> [junit4:junit4]   2> 391202 T477 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
>> [junit4:junit4]   2> 391202 T477 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
>> [junit4:junit4]   2> 391211 T477 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
>> [junit4:junit4]   2> 391211 T477 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
>> [junit4:junit4]   2> 391229 T477 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
>> [junit4:junit4]   2> 391231 T477 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
>> [junit4:junit4]   2> 391244 T477 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
>> [junit4:junit4]   2> 391245 T477 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
>> [junit4:junit4]   2> 392150 T477 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
>> [junit4:junit4]   2> 392150 T477 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
>> [junit4:junit4]   2> 392287 T477 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
>> [junit4:junit4]   2> 392288 T477 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
>> [junit4:junit4]   2> 392300 T477 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
>> [junit4:junit4]   2> 392302 T477 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
>> [junit4:junit4]   2> 393458 T477 oejs.Server.doStart jetty-8.1.10.v20130312
>> [junit4:junit4]   2> 393544 T477 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51209
>> [junit4:junit4]   2> 393545 T477 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
>> [junit4:junit4]   2> 393546 T477 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
>> [junit4:junit4]   2> 393546 T477 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369134468973
>> [junit4:junit4]   2> 393547 T477 oasc.CoreContainer$Initializer.initialize looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369134468973/solr.xml
>> [junit4:junit4]   2> 393548 T477 oasc.CoreContainer.<init> New CoreContainer 459798905
>> [junit4:junit4]   2> 393548 T477 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369134468973/'
>> [junit4:junit4]   2> 393549 T477 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369134468973/'
>> [junit4:junit4]   2> 393792 T477 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369134468973
>> [junit4:junit4]   2> 393794 T477 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369134468973/collection1
>> [junit4:junit4]   2> 393796 T477 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369134468973/collection1/conf
>> [junit4:junit4]   2> 394008 T477 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369134468973/collection1/conf/xslt
>> [junit4:junit4]   2> 394015 T477 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369134468973/collection1/lib
>> [junit4:junit4]   2> 394025 T477 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369134468973/collection1/lib/classes
>> [junit4:junit4]   2> 394038 T477 oasc.SolrCoreDiscoverer.addCore Discovered properties file /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369134468973/conf/core.properties, adding to cores
>> [junit4:junit4]   2> 394056 T477 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
>> [junit4:junit4]   2> 394057 T477 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
>> [junit4:junit4]   2> 394058 T477 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
>> [junit4:junit4]   2> 394058 T477 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
>> [junit4:junit4]   2> 394059 T477 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
>> [junit4:junit4]   2> 394060 T477 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
>> [junit4:junit4]   2> 394060 T477 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
>> [junit4:junit4]   2> 394061 T477 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
>> [junit4:junit4]   2> 394061 T477 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
>> [junit4:junit4]   2> 394062 T477 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
>> [junit4:junit4]   2> 394108 T477 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
>> [junit4:junit4]   2> 394109 T477 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51206/solr
>> [junit4:junit4]   2> 394136 T477 oasc.ZkController.checkChrootPath zkHost includes chroot
>> [junit4:junit4]   2> 394139 T477 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
>> [junit4:junit4]   2> 394148 T497 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@50925f4e name:ZooKeeperConnection Watcher:127.0.0.1:51206 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
>> [junit4:junit4]   2> 394152 T477 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
>> [junit4:junit4]   2> 394175 T477 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
>> [junit4:junit4]   2> 394221 T477 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
>> [junit4:junit4]   2> 394227 T499 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7fdb3a16 name:ZooKeeperConnection Watcher:127.0.0.1:51206/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
>> [junit4:junit4]   2> 394228 T477 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
>> [junit4:junit4]   2> 394234 T477 oascc.SolrZkClient.makePath makePath: /overseer/queue
>> [junit4:junit4]   2> 394247 T477 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
>> [junit4:junit4]   2> 394260 T477 oascc.SolrZkClient.makePath makePath: /live_nodes
>> [junit4:junit4]   2> 394268 T477 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51209_
>> [junit4:junit4]   2> 394271 T477 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51209_
>> [junit4:junit4]   2> 394290 T477 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
>> [junit4:junit4]   2> 394308 T477 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
>> [junit4:junit4]   2> 394317 T477 oasc.Overseer.start Overseer (id=89727596464111619-127.0.0.1:51209_-n_0000000000) starting
>> [junit4:junit4]   2> 394369 T477 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
>> [junit4:junit4]   2> 394403 T501 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
>> [junit4:junit4]   2> 394409 T477 oascc.SolrZkClient.makePath makePath: /clusterstate.json
>> [junit4:junit4]   2> 394426 T477 oascc.SolrZkClient.makePath makePath: /aliases.json
>> [junit4:junit4]   2> 394436 T477 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
>> [junit4:junit4]   2> 394489 T500 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
>> [junit4:junit4]   2> 394511 T477 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
>> [junit4:junit4]   2> 394512 T477 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
>> [junit4:junit4]   2> 394512 T477 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
>> [junit4:junit4]   2> 394548 T477 oascsi.HttpClientUtil.createClient Creating new http client, config:
>> [junit4:junit4]   2> 394566 T477 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
>> [junit4:junit4]   2> 394578 T504 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7c16952a name:ZooKeeperConnection Watcher:127.0.0.1:51206/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
>> [junit4:junit4]   2> 394578 T477 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
>> [junit4:junit4]   2> 394585 T477 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
>> [junit4:junit4]   2> 394604 T477 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
>> [junit4:junit4]   2> 395368 T477 oejs.Server.doStart jetty-8.1.10.v20130312
>> [junit4:junit4]   2> 395377 T477 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51213
>> [junit4:junit4]   2> 395378 T477 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
>> [junit4:junit4]   2> 395379 T477 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
>> [junit4:junit4]   2> 395379 T477 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260
>> [junit4:junit4]   2> 395380 T477 oasc.CoreContainer$Initializer.initialize looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260/solr.xml
>> [junit4:junit4]   2> 395380 T477 oasc.CoreContainer.<init> New CoreContainer 1387197548
>> [junit4:junit4]   2> 395381 T477 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260/'
>> [junit4:junit4]   2> 395382 T477 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260/'
>> [junit4:junit4]   2> 395636 T477 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260
>> [junit4:junit4]   2> 395638 T477 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260/collection1
>> [junit4:junit4]   2> 395641 T477 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260/collection1/conf
>> [junit4:junit4]   2> 395897 T477 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260/collection1/conf/xslt
>> [junit4:junit4]   2> 395905 T477 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260/collection1/lib
>> [junit4:junit4]   2> 395908 T477 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260/collection1/lib/classes
>> [junit4:junit4]   2> 395912 T477 oasc.SolrCoreDiscoverer.addCore Discovered properties file /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260/conf/core.properties, adding to cores
>> [junit4:junit4]   2> 395938 T477 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
>> [junit4:junit4]   2> 395939 T477 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
>> [junit4:junit4]   2> 395940 T477 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
>> [junit4:junit4]   2> 395941 T477 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
>> [junit4:junit4]   2> 395942 T477 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
>> [junit4:junit4]   2> 395943 T477 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
>> [junit4:junit4]   2> 395944 T477 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
>> [junit4:junit4]   2> 395944 T477 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
>> [junit4:junit4]   2> 395948 T477 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
>> [junit4:junit4]   2> 395958 T477 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
>> [junit4:junit4]   2> 395995 T477 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
>> [junit4:junit4]   2> 395997 T477 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51206/solr
>> [junit4:junit4]   2> 395997 T477 oasc.ZkController.checkChrootPath zkHost includes chroot
>> [junit4:junit4]   2> 396001 T477 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
>> [junit4:junit4]   2> 396013 T515 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5b2be3db name:ZooKeeperConnection Watcher:127.0.0.1:51206 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
>> [junit4:junit4]   2> 396015 T477 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
>> [junit4:junit4]   2> 396030 T477 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
>> [junit4:junit4]   2> 396081 T477 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
>> [junit4:junit4]   2> 396092 T517 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1836691b name:ZooKeeperConnection Watcher:127.0.0.1:51206/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
>> [junit4:junit4]   2> 396093 T477 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
>> [junit4:junit4]   2> 396121 T477 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
>> [junit4:junit4]   2> 397155 T477 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51213_
>> [junit4:junit4]   2> 397158 T477 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51213_
>> [junit4:junit4]   2> 397167 T517 oascc.ZkStateReader$3.process Updating live nodes... (2)
>> [junit4:junit4]   2> 397173 T504 oascc.ZkStateReader$3.process Updating live nodes... (2)
>> [junit4:junit4]   2> 397176 T499 oascc.ZkStateReader$3.process Updating live nodes... (2)
>> [junit4:junit4]   2> 397197 T477 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
>> [junit4:junit4]   2> 397198 T477 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
>> [junit4:junit4]   2> 397199 T477 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
>> [junit4:junit4]   2> 397994 T477 oejs.Server.doStart jetty-8.1.10.v20130312
>> [junit4:junit4]   2> 398005 T477 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51216
>> [junit4:junit4]   2> 398007 T477 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
>> [junit4:junit4]   2> 398007 T477 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
>> [junit4:junit4]   2> 398008 T477 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876
>> [junit4:junit4]   2> 398008 T477 oasc.CoreContainer$Initializer.initialize looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876/solr.xml
>> [junit4:junit4]   2> 398009 T477 oasc.CoreContainer.<init> New CoreContainer 1797971966
>> [junit4:junit4]   2> 398009 T477 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876/'
>> [junit4:junit4]   2> 398010 T477 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876/'
>> [junit4:junit4]   2> 398714 T477 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876
>> [junit4:junit4]   2> 398716 T477 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876/collection1
>> [junit4:junit4]   2> 398717 T477 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876/collection1/conf
>> [junit4:junit4]   2> 398920 T477 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876/collection1/conf/xslt
>> [junit4:junit4]   2> 398926 T477 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876/collection1/lib
>> [junit4:junit4]   2> 398927 T477 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876/collection1/lib/classes
>> [junit4:junit4]   2> 398931 T477 oasc.SolrCoreDiscoverer.addCore Discovered properties file /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876/conf/core.properties, adding to cores
>> [junit4:junit4]   2> 398952 T477 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
>> [junit4:junit4]   2> 398954 T477 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
>> [junit4:junit4]   2> 398955 T477 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
>> [junit4:junit4]   2> 398955 T477 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
>> [junit4:junit4]   2> 398956 T477 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
>> [junit4:junit4]   2> 398956 T477 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
>> [junit4:junit4]   2> 398957 T477 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
>> [junit4:junit4]   2> 398957 T477 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
>> [junit4:junit4]   2> 398958 T477 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
>> [junit4:junit4]   2> 398958 T477 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
>> [junit4:junit4]   2> 399004 T477 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
>> [junit4:junit4]   2> 399005 T477 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51206/solr
>> [junit4:junit4]   2> 399006 T477 oasc.ZkController.checkChrootPath zkHost includes chroot
>> [junit4:junit4]   2> 399008 T477 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
>> [junit4:junit4]   2> 399016 T529 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@512ff979 name:ZooKeeperConnection Watcher:127.0.0.1:51206 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
>> [junit4:junit4]   2> 399017 T477 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
>> [junit4:junit4]   2> 399037 T477 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
>> [junit4:junit4]   2> 399092 T477 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
>> [junit4:junit4]   2> 399100 T531 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5e19c8ca name:ZooKeeperConnection Watcher:127.0.0.1:51206/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
>> [junit4:junit4]   2> 399100 T477 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
>> [junit4:junit4]   2> 399119 T477 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
>> [junit4:junit4]   2> 400136 T477 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51216_
>> [junit4:junit4]   2> 400140 T477 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51216_
>> [junit4:junit4]   2> 400150 T517 oascc.ZkStateReader$3.process Updating live nodes... (3)
>> [junit4:junit4]   2> 400153 T504 oascc.ZkStateReader$3.process Updating live nodes... (3)
>> [junit4:junit4]   2> 400201 T499 oascc.ZkStateReader$3.process Updating live nodes... (3)
>> [junit4:junit4]   2> 400202 T531 oascc.ZkStateReader$3.process Updating live nodes... (3)
>> [junit4:junit4]   2> 400217 T477 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
>> [junit4:junit4]   2> 400218 T477 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
>> [junit4:junit4]   2> 400219 T477 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
>> [junit4:junit4]   2> 401042 T477 oejs.Server.doStart jetty-8.1.10.v20130312
>> [junit4:junit4]   2> 401053 T477 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51219
>> [junit4:junit4]   2> 401078 T477 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
>> [junit4:junit4]   2> 401079 T477 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
>> [junit4:junit4]   2> 401079 T477 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911
>> [junit4:junit4]   2> 401080 T477 oasc.CoreContainer$Initializer.initialize looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/solr.xml
>> [junit4:junit4]   2> 401080 T477 oasc.CoreContainer.<init> New CoreContainer 1776409284
>> [junit4:junit4]   2> 401082 T477 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/'
>> [junit4:junit4]   2> 401082 T477 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/'
>> [junit4:junit4]   2> 401293 T477 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911
>> [junit4:junit4]   2> 401296 T477 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/collection1
>> [junit4:junit4]   2> 401297 T477 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/collection1/conf
>> [junit4:junit4]   2> 401518 T477 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/collection1/conf/xslt
>> [junit4:junit4]   2> 401526 T477 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/collection1/lib
>> [junit4:junit4]   2> 401537 T477 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/collection1/lib/classes
>> [junit4:junit4]   2> 401545 T477 oasc.SolrCoreDiscoverer.addCore Discovered properties file /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/conf/core.properties, adding to cores
>> [junit4:junit4]   2> 401564 T477 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
>> [junit4:junit4]   2> 401565 T477 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
>> [junit4:junit4]   2> 401565 T477 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
>> [junit4:junit4]   2> 401565 T477 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
>> [junit4:junit4]   2> 401566 T477 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
>> [junit4:junit4]   2> 401567 T477 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
>> [junit4:junit4]   2> 401567 T477 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
>> [junit4:junit4]   2> 401568 T477 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
>> [junit4:junit4]   2> 401568 T477 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
>> [junit4:junit4]   2> 401569 T477 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
>> [junit4:junit4]   2> 401601 T477 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
>> [junit4:junit4]   2> 401602 T477 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51206/solr
>> [junit4:junit4]   2> 401603 T477 oasc.ZkController.checkChrootPath zkHost includes chroot
>> [junit4:junit4]   2> 401611 T477 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
>> [junit4:junit4]   2> 401619 T543 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3415f88f name:ZooKeeperConnection Watcher:127.0.0.1:51206 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
>> [junit4:junit4]   2> 401621 T477 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
>> [junit4:junit4]   2> 401631 T477 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
>> [junit4:junit4]   2> 401664 T477 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
>> [junit4:junit4]   2> 401671 T545 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6128bf05 name:ZooKeeperConnection Watcher:127.0.0.1:51206/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
>> [junit4:junit4]   2> 401671 T477 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
>> [junit4:junit4]   2> 401696 T477 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
>> [junit4:junit4]   2> 402712 T477 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51219_
>> [junit4:junit4]   2> 402716 T477 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51219_
>> [junit4:junit4]   2> 402733 T504 oascc.ZkStateReader$3.process Updating live nodes... (4)
>> [junit4:junit4]   2> 402734 T517 oascc.ZkStateReader$3.process Updating live nodes... (4)
>> [junit4:junit4]   2> 402737 T545 oascc.ZkStateReader$3.process Updating live nodes... (4)
>> [junit4:junit4]   2> 402740 T531 oascc.ZkStateReader$3.process Updating live nodes... (4)
>> [junit4:junit4]   2> 402741 T499 oascc.ZkStateReader$3.process Updating live nodes... (4)
>> [junit4:junit4]   2> 402754 T477 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
>> [junit4:junit4]   2> 402755 T477 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
>> [junit4:junit4]   2> 402755 T477 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
>> [junit4:junit4]   2> 403735 T477 oejs.Server.doStart jetty-8.1.10.v20130312
>> [junit4:junit4]   2> 403747 T477 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51222
>> [junit4:junit4]   2> 403750 T477 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
>> [junit4:junit4]   2> 403751 T477 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
>> [junit4:junit4]   2> 403752 T477 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369134479435
>> [junit4:junit4]   2> 403752 T477 oasc.CoreContainer$Initializer.initialize looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369134479435/solr.xml
>> [junit4:junit4]   2> 403753 T477 oasc.CoreContainer.<init> New CoreContainer 1612640675
>> [junit4:junit4]   2> 403753 T477 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369134479435/'
>> [junit4:junit4]   2> 403754 T477 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369134479435/'
>> [junit4:junit4]   2> 403962 T477 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369134479435
>> [junit4:junit4]   2> 403963 T477 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369134479435/collection1
>> [junit4:junit4]   2> 403965 T477 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369134479435/collection1/conf
>> [junit4:junit4]   2> 404176 T477 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369134479435/collection1/conf/xslt
>> [junit4:junit4]   2> 404181 T477 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369134479435/collection1/lib
>> [junit4:junit4]   2> 404184 T477 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369134479435/collection1/lib/classes
>> [junit4:junit4]   2> 404187 T477 oasc.SolrCoreDiscoverer.addCore Discovered properties file /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369134479435/conf/core.properties, adding to cores
>> [junit4:junit4]   2> 404211 T477 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
>> [junit4:junit4]   2> 404213 T477 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
>> [junit4:junit4]   2> 404214 T477 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
>> [junit4:junit4]   2> 404215 T477 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
>> [junit4:junit4]   2> 404216 T477 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
>> [junit4:junit4]   2> 404218 T477 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
>> [junit4:junit4]   2> 404219 T477 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
>> [junit4:junit4]   2> 404220 T477 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
>> [junit4:junit4]   2> 404221 T477 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
>> [junit4:junit4]   2> 404222 T477 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
>> [junit4:junit4]   2> 404267 T477 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
>> [junit4:junit4]   2> 404268 T477 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51206/solr
>> [junit4:junit4]   2> 404268 T477 oasc.ZkController.checkChrootPath zkHost includes chroot
>> [junit4:junit4]   2> 404272 T477 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
>> [junit4:junit4]   2> 404298 T557 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@73856c07 name:ZooKeeperConnection Watcher:127.0.0.1:51206 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
>> [junit4:junit4]   2> 404301 T477 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
>> [junit4:junit4]   2> 404310 T477 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
>> [junit4:junit4]   2> 404343 T477 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
>> [junit4:junit4]   2> 404352 T559 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5225c593 name:ZooKeeperConnection Watcher:127.0.0.1:51206/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
>> [junit4:junit4]   2> 404353 T477 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
>> [junit4:junit4]   2> 404383 T477 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
>> [junit4:junit4]   2> 405403 T477 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51222_
>> [junit4:junit4]   2> 405408 T477 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51222_
>> [junit4:junit4]   2> 405474 T531 oascc.ZkStateReader$3.process Updating live nodes... (5)
>> [junit4:junit4]   2> 405475 T559 oascc.ZkStateReader$3.process Updating live nodes... (5)
>> [junit4:junit4]   2> 405487 T517 oascc.ZkStateReader$3.process Updating live nodes... (5)
>> [junit4:junit4]   2> 405487 T504 oascc.ZkStateReader$3.process Updating live nodes... (5)
>> [junit4:junit4]   2> 405488 T545 oascc.ZkStateReader$3.process Updating live nodes... (5)
>> [junit4:junit4]   2> 405489 T499 oascc.ZkStateReader$3.process Updating live nodes... (5)
>> [junit4:junit4]   2> 405506 T477 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
>> [junit4:junit4]   2> 405507 T477 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
>> [junit4:junit4]   2> 405508 T477 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
>> [junit4:junit4]   2> 405569 T477 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
>> [junit4:junit4]   2> 405643 T510 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=2&name=nodes_used_collection&replicationFactor=2&action=CREATE&wt=javabin&version=2
>> [junit4:junit4]   2> 405664 T499 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
>> [junit4:junit4]   2> 405684 T501 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000000 message:{
>> [junit4:junit4]   2>    "operation":"createcollection",
>> [junit4:junit4]   2>    "numShards":"2",
>> [junit4:junit4]   2>    "maxShardsPerNode":null,
>> [junit4:junit4]   2>    "createNodeSet":null,
>> [junit4:junit4]   2>    "name":"nodes_used_collection",
>> [junit4:junit4]   2>    "replicationFactor":"2"}
>> [junit4:junit4]   2> 405685 T501 oasc.OverseerCollectionProcessor.createCollection Creating shard nodes_used_collection_shard1_replica1 as part of slice shard1 of collection nodes_used_collection on 127.0.0.1:51213_
>> [junit4:junit4]   2> 405686 T501 oasc.OverseerCollectionProcessor.createCollection Creating shard nodes_used_collection_shard1_replica2 as part of slice shard1 of collection nodes_used_collection on 127.0.0.1:51209_
>> [junit4:junit4]   2> 405690 T501 oasc.OverseerCollectionProcessor.createCollection Creating shard nodes_used_collection_shard2_replica1 as part of slice shard2 of collection nodes_used_collection on 127.0.0.1:51219_
>> [junit4:junit4]   2> 405691 T501 oasc.OverseerCollectionProcessor.createCollection Creating shard nodes_used_collection_shard2_replica2 as part of slice shard2 of collection nodes_used_collection on 127.0.0.1:51216_
>> [junit4:junit4]   2> 405707 T499 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
>> [junit4:junit4]   2> 405740 T527 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard2_replica2' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876/nodes_used_collection_shard2_replica2
>> [junit4:junit4]   2> 405742 T527 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
>> [junit4:junit4]   2> 405745 T511 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard1_replica1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260/nodes_used_collection_shard1_replica1
>> [junit4:junit4]   2> 405747 T511 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
>> [junit4:junit4]   2> 405750 T541 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard2_replica1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/nodes_used_collection_shard2_replica1
>> [junit4:junit4]   2> 405753 T541 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
>> [junit4:junit4]   2> 405757 T494 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard1_replica2' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369134468973/nodes_used_collection_shard1_replica2
>> [junit4:junit4]   2> 405758 T494 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
>> [junit4:junit4]   2> 405763 T527 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
>> [junit4:junit4]   2> 405764 T527 oasc.ZkController.getConfName Looking for collection configName
>> [junit4:junit4]   2> 405771 T541 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
>> [junit4:junit4]   2> 405773 T541 oasc.ZkController.getConfName Looking for collection configName
>> [junit4:junit4]   2> 405773 T511 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
>> [junit4:junit4]   2> 405774 T511 oasc.ZkController.getConfName Looking for collection configName
>> [junit4:junit4]   2> 405776 T494 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
>> [junit4:junit4]   2> 405777 T494 oasc.ZkController.getConfName Looking for collection configName
>> [junit4:junit4]   2> 405782 T527 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
>> [junit4:junit4]   2> 405783 T527 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
>> [junit4:junit4]   2> 405792 T511 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
>> [junit4:junit4]   2> 405794 T511 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
>> [junit4:junit4]   2> 405795 T494 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
>> [junit4:junit4]   2> 405796 T494 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
>> [junit4:junit4]   2> 405798 T541 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
>> [junit4:junit4]   2> 405800 T541 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
>> [junit4:junit4]   2> 405809 T527 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
>> [junit4:junit4]   2> 405817 T511 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
>> [junit4:junit4]   2> 405817 T494 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
>> [junit4:junit4]   2> 405824 T541 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
>> [junit4:junit4]   2> 405828 T527 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876/nodes_used_collection_shard2_replica2/'
>> [junit4:junit4]   2> 405835 T541 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/nodes_used_collection_shard2_replica1/'
>> [junit4:junit4]   2> 405845 T511 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260/nodes_used_collection_shard1_replica1/'
>> [junit4:junit4]   2> 405845 T494 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369134468973/nodes_used_collection_shard1_replica2/'
>> [junit4:junit4]   2> 406340 T541 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
>> [junit4:junit4]   2> 406353 T511 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
>> [junit4:junit4]   2> 406387 T494 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
>> [junit4:junit4]   2> 406418 T527 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
>> [junit4:junit4]   2> 406776 T494 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
>> [junit4:junit4]   2> 406822 T494 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
>> [junit4:junit4]   2> 406854 T494 oass.IndexSchema.readSchema [nodes_used_collection_shard1_replica2] Schema name=test
>> [junit4:junit4]   2> 406883 T541 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
>> [junit4:junit4]   2> 406885 T527 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
>> [junit4:junit4]   2> 406900 T527 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
>> [junit4:junit4]   2> 406924 T541 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
>> [junit4:junit4]   2> 406973 T511 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
>> [junit4:junit4]   2> 406979 T511 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
>> [junit4:junit4]   2> 406989 T541 oass.IndexSchema.readSchema [nodes_used_collection_shard2_replica1] Schema name=test
>> [junit4:junit4]   2> 407003 T527 oass.IndexSchema.readSchema [nodes_used_collection_shard2_replica2] Schema name=test
>> [junit4:junit4]   2> 407134 T511 oass.IndexSchema.readSchema [nodes_used_collection_shard1_replica1] Schema name=test
>> [junit4:junit4]   2> 410949 T494 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
>> [junit4:junit4]   2> 411013 T494 oass.IndexSchema.readSchema default search field in schema is text
>> [junit4:junit4]   2> 411030 T494 oass.IndexSchema.readSchema unique key field: id
>> [junit4:junit4]   2> 411156 T527 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
>> [junit4:junit4]   2> 411208 T527 oass.IndexSchema.readSchema default search field in schema is text
>> [junit4:junit4]   2> 411241 T511 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
>> [junit4:junit4]   2> 411281 T527 oass.IndexSchema.readSchema unique key field: id
>> [junit4:junit4]   2> 411369 T511 oass.IndexSchema.readSchema default search field in schema is text
>> [junit4:junit4]   2> 411372 T494 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
>> [junit4:junit4]   2> 411377 T541 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
>> [junit4:junit4]   2> 411380 T511 oass.IndexSchema.readSchema unique key field: id
>> [junit4:junit4]   2> 411406 T494 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
>> [junit4:junit4]   2> 411418 T494 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
>> [junit4:junit4]   2> 411452 T541 oass.IndexSchema.readSchema default search field in schema is text
>> [junit4:junit4]   2> 411459 T494 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
>> [junit4:junit4]   2> 411459 T494 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
>> [junit4:junit4]   2> 411460 T494 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
>> [junit4:junit4]   2> 411469 T494 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
>> [junit4:junit4]   2> 411470 T494 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
>> [junit4:junit4]   2> 411470 T494 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
>> [junit4:junit4]   2> 411471 T494 oasc.SolrCore.<init> [nodes_used_collection_shard1_replica2] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369134468973/nodes_used_collection_shard1_replica2/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369134468973/nodes_used_collection_shard1_replica2/data/
>> [junit4:junit4]   2> 411475 T541 oass.IndexSchema.readSchema unique key field: id
>> [junit4:junit4]   2> 411478 T494 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3248f37e
>> [junit4:junit4]   2> 411504 T494 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
>> [junit4:junit4]   2> 411516 T494 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369134468973/nodes_used_collection_shard1_replica2/data
>> [junit4:junit4]   2> 411517 T494 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369134468973/nodes_used_collection_shard1_replica2/data/index/
>> [junit4:junit4]   2> 411517 T494 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard1_replica2] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369134468973/nodes_used_collection_shard1_replica2/data/index' doesn't exist. Creating new index...
>> [junit4:junit4]   2> 411530 T494 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369134468973/nodes_used_collection_shard1_replica2/data/index
>> [junit4:junit4]   2> 411562 T494 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
>> [junit4:junit4]   2>          commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@a44eeb7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@5164bc93),segFN=segments_1,generation=1}
>> [junit4:junit4]   2> 411563 T494 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
>> [junit4:junit4]   2> 411572 T494 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
>> [junit4:junit4]   2> 411573 T494 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
>> [junit4:junit4]   2> 411574 T494 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
>> [junit4:junit4]   2> 411576 T494 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
>> [junit4:junit4]   2> 411577 T527 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
>> [junit4:junit4]   2> 411585 T494 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
>> [junit4:junit4]   2> 411591 T494 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
>> [junit4:junit4]   2> 411594 T494 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
>> [junit4:junit4]   2> 411596 T494 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
>> [junit4:junit4]   2> 411598 T494 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
>> [junit4:junit4]   2> 411670 T527 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
>> [junit4:junit4]   2> 411675 T511 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
>> [junit4:junit4]   2> 411685 T527 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
>> [junit4:junit4]   2> 411706 T511 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
>> [junit4:junit4]   2> 411711 T494 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
>> [junit4:junit4]   2> 411715 T527 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
>> [junit4:junit4]   2> 411732 T527 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
>> [junit4:junit4]   2> 411733 T527 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
>> [junit4:junit4]   2> 411729 T511 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
>> [junit4:junit4]   2> 411727 T541 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
>> [junit4:junit4]   2> 411741 T527 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
>> [junit4:junit4]   2> 411741 T527 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
>> [junit4:junit4]   2> 411742 T527 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
>> [junit4:junit4]   2> 411742 T527 oasc.SolrCore.<init> [nodes_used_collection_shard2_replica2] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876/nodes_used_collection_shard2_replica2/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876/nodes_used_collection_shard2_replica2/data/
>> [junit4:junit4]   2> 411743 T527 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3248f37e
>> [junit4:junit4]   2> 411743 T527 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
>> [junit4:junit4]   2> 411745 T527 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876/nodes_used_collection_shard2_replica2/data
>> [junit4:junit4]   2> 411745 T527 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876/nodes_used_collection_shard2_replica2/data/index/
>> [junit4:junit4]   2> 411746 T527 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard2_replica2] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876/nodes_used_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
>> [junit4:junit4]   2> 411747 T527 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876/nodes_used_collection_shard2_replica2/data/index
>> [junit4:junit4]   2> 411749 T511 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
>> [junit4:junit4]   2> 411750 T511 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
>> [junit4:junit4]   2> 411751 T511 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
>> [junit4:junit4]   2> 411722 T494 oass.SolrIndexSearcher.<init> Opening Searcher@1ce64076 main
>> [junit4:junit4]   2> 411752 T494 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369134468973/nodes_used_collection_shard1_replica2/data/tlog
>> [junit4:junit4]   2> 411756 T494 oasu.CommitTracker.<init> Hard AutoCommit: disabled
>> [junit4:junit4]   2> 411756 T494 oasu.CommitTracker.<init> Soft AutoCommit: disabled
>> [junit4:junit4]   2> 411763 T511 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
>> [junit4:junit4]   2> 411764 T511 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
>> [junit4:junit4]   2> 411764 T565 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica2] Registered new searcher Searcher@1ce64076 main{StandardDirectoryReader(segments_1:1)}
>> [junit4:junit4]   2> 411769 T494 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica2 state=down
>> [junit4:junit4]   2> 411771 T527 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
>> [junit4:junit4]   2>          commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@43b9d518 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4b06504d),segFN=segments_1,generation=1}
>> [junit4:junit4]   2> 411771 T527 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
>> [junit4:junit4]   2> 411765 T511 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
>> [junit4:junit4]   2> 411776 T527 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
>> [junit4:junit4]   2> 411785 T527 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
>> [junit4:junit4]   2> 411769 T541 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
>> [junit4:junit4]   2> 411786 T527 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
>> [junit4:junit4]   2> 411776 T511 oasc.SolrCore.<init> [nodes_used_collection_shard1_replica1] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260/nodes_used_collection_shard1_replica1/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260/nodes_used_collection_shard1_replica1/data/
>> [junit4:junit4]   2> 411789 T511 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3248f37e
>> [junit4:junit4]   2> 411790 T511 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
>> [junit4:junit4]   2> 411787 T527 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
>> [junit4:junit4]   2> 411793 T527 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
>> [junit4:junit4]   2> 411793 T527 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
>> [junit4:junit4]   2> 411794 T527 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
>> [junit4:junit4]   2> 411795 T527 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
>> [junit4:junit4]   2> 411799 T527 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
>> [junit4:junit4]   2> 411801 T511 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260/nodes_used_collection_shard1_replica1/data
>> [junit4:junit4]   2> 411801 T511 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260/nodes_used_collection_shard1_replica1/data/index/
>> [junit4:junit4]   2> 411802 T511 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard1_replica1] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260/nodes_used_collection_shard1_replica1/data/index' doesn't exist. Creating new index...
>> [junit4:junit4]   2> 411809 T511 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260/nodes_used_collection_shard1_replica1/data/index
>> [junit4:junit4]   2> 411827 T527 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
>> [junit4:junit4]   2> 411847 T541 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
>> [junit4:junit4]   2> 411862 T541 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
>> [junit4:junit4]   2> 411863 T541 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
>> [junit4:junit4]   2> 411863 T541 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
>> [junit4:junit4]   2> 411863 T511 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
>> [junit4:junit4]   2>          commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2f36a361 lockFactory=org.apache.lucene.store.NativeFSLockFactory@646cb8c7),segFN=segments_1,generation=1}
>> [junit4:junit4]   2> 411865 T511 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
>> [junit4:junit4]   2> 411869 T541 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
>> [junit4:junit4]   2> 411869 T541 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
>> [junit4:junit4]   2> 411870 T541 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
>> [junit4:junit4]   2> 411870 T511 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
>> [junit4:junit4]   2> 411871 T527 oass.SolrIndexSearcher.<init> Opening Searcher@417dbcb6 main
>> [junit4:junit4]   2> 411871 T541 oasc.SolrCore.<init> [nodes_used_collection_shard2_replica1] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/nodes_used_collection_shard2_replica1/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/nodes_used_collection_shard2_replica1/data/
>> [junit4:junit4]   2> 411872 T527 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876/nodes_used_collection_shard2_replica2/data/tlog
>> [junit4:junit4]   2> 411871 T511 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
>> [junit4:junit4]   2> 411874 T511 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
>> [junit4:junit4]   2> 411872 T541 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3248f37e
>> [junit4:junit4]   2> 411875 T511 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
>> [junit4:junit4]   2> 411874 T527 oasu.CommitTracker.<init> Hard AutoCommit: disabled
>> [junit4:junit4]   2> 411876 T527 oasu.CommitTracker.<init> Soft AutoCommit: disabled
>> [junit4:junit4]   2> 411876 T511 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
>> [junit4:junit4]   2> 411877 T511 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
>> [junit4:junit4]   2> 411882 T511 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
>> [junit4:junit4]   2> 411883 T511 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
>> [junit4:junit4]   2> 411884 T511 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
>> [junit4:junit4]   2> 411875 T541 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
>> [junit4:junit4]   2> 411881 T566 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica2] Registered new searcher Searcher@417dbcb6 main{StandardDirectoryReader(segments_1:1)}
>> [junit4:junit4]   2> 411916 T541 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/nodes_used_collection_shard2_replica1/data
>> [junit4:junit4]   2> 411916 T541 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/nodes_used_collection_shard2_replica1/data/index/
>> [junit4:junit4]   2> 411917 T541 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard2_replica1] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/nodes_used_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
>> [junit4:junit4]   2> 411917 T511 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
>> [junit4:junit4]   2> 411919 T527 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica2 state=down
>> [junit4:junit4]   2> 411921 T541 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/nodes_used_collection_shard2_replica1/data/index
>> [junit4:junit4]   2> 411931 T511 oass.SolrIndexSearcher.<init> Opening Searcher@1d5ff550 main
>> [junit4:junit4]   2> 411931 T541 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
>> [junit4:junit4]   2>          commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3f65a49 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4da90726),segFN=segments_1,generation=1}
>> [junit4:junit4]   2> 411933 T541 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
>> [junit4:junit4]   2> 411932 T511 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260/nodes_used_collection_shard1_replica1/data/tlog
>> [junit4:junit4]   2> 411935 T511 oasu.CommitTracker.<init> Hard AutoCommit: disabled
>> [junit4:junit4]   2> 411935 T511 oasu.CommitTracker.<init> Soft AutoCommit: disabled
>> [junit4:junit4]   2> 411937 T541 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
>> [junit4:junit4]   2> 411937 T541 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
>> [junit4:junit4]   2> 411938 T541 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
>> [junit4:junit4]   2> 411939 T541 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
>> [junit4:junit4]   2> 411940 T541 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
>> [junit4:junit4]   2> 411941 T541 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
>> [junit4:junit4]   2> 411941 T567 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica1] Registered new searcher Searcher@1d5ff550 main{StandardDirectoryReader(segments_1:1)}
>> [junit4:junit4]   2> 411941 T541 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
>> [junit4:junit4]   2> 411943 T541 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
>> [junit4:junit4]   2> 411943 T541 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
>> [junit4:junit4]   2> 411945 T511 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=down
>> [junit4:junit4]   2> 411966 T541 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
>> [junit4:junit4]   2> 411977 T541 oass.SolrIndexSearcher.<init> Opening Searcher@11f5e3d3 main
>> [junit4:junit4]   2> 411977 T541 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/nodes_used_collection_shard2_replica1/data/tlog
>> [junit4:junit4]   2> 411984 T541 oasu.CommitTracker.<init> Hard AutoCommit: disabled
>> [junit4:junit4]   2> 411988 T541 oasu.CommitTracker.<init> Soft AutoCommit: disabled
>> [junit4:junit4]   2> 411993 T568 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica1] Registered new searcher Searcher@11f5e3d3 main{StandardDirectoryReader(segments_1:1)}
>> [junit4:junit4]   2> 411996 T541 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica1 state=down
>> [junit4:junit4]   2> 412746 T500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
>> [junit4:junit4]   2> 412749 T500 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
>> [junit4:junit4]   2>    "operation":"state",
>> [junit4:junit4]   2>    "core_node_name":null,
>> [junit4:junit4]   2>    "numShards":"2",
>> [junit4:junit4]   2>    "shard":"shard1",
>> [junit4:junit4]   2>    "roles":null,
>> [junit4:junit4]   2>    "state":"down",
>> [junit4:junit4]   2>    "shard_state":"active",
>> [junit4:junit4]   2>    "core":"nodes_used_collection_shard1_replica2",
>> [junit4:junit4]   2>    "collection":"nodes_used_collection",
>> [junit4:junit4]   2>    "shard_range":null,
>> [junit4:junit4]   2>    "node_name":"127.0.0.1:51209_",
>> [junit4:junit4]   2>    "base_url":"http://127.0.0.1:51209"}
>> [junit4:junit4]   2> 412749 T500 oasc.Overseer$ClusterStateUpdater.createCollection Create collection nodes_used_collection with numShards 2
>> [junit4:junit4]   2> 412800 T500 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
>> [junit4:junit4]   2>    "operation":"state",
>> [junit4:junit4]   2>    "core_node_name":null,
>> [junit4:junit4]   2>    "numShards":"2",
>> [junit4:junit4]   2>    "shard":"shard2",
>> [junit4:junit4]   2>    "roles":null,
>> [junit4:junit4]   2>    "state":"down",
>> [junit4:junit4]   2>    "shard_state":"active",
>> [junit4:junit4]   2>    "core":"nodes_used_collection_shard2_replica2",
>> [junit4:junit4]   2>    "collection":"nodes_used_collection",
>> [junit4:junit4]   2>    "shard_range":null,
>> [junit4:junit4]   2>    "node_name":"127.0.0.1:51216_",
>> [junit4:junit4]   2>    "base_url":"http://127.0.0.1:51216"}
>> [junit4:junit4]   2> 412819 T500 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
>> [junit4:junit4]   2>    "operation":"state",
>> [junit4:junit4]   2>    "core_node_name":null,
>> [junit4:junit4]   2>    "numShards":"2",
>> [junit4:junit4]   2>    "shard":"shard1",
>> [junit4:junit4]   2>    "roles":null,
>> [junit4:junit4]   2>    "state":"down",
>> [junit4:junit4]   2>    "shard_state":"active",
>> [junit4:junit4]   2>    "core":"nodes_used_collection_shard1_replica1",
>> [junit4:junit4]   2>    "collection":"nodes_used_collection",
>> [junit4:junit4]   2>    "shard_range":null,
>> [junit4:junit4]   2>    "node_name":"127.0.0.1:51213_",
>> [junit4:junit4]   2>    "base_url":"http://127.0.0.1:51213"}
>> [junit4:junit4]   2> 412836 T500 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
>> [junit4:junit4]   2>    "operation":"state",
>> [junit4:junit4]   2>    "core_node_name":null,
>> [junit4:junit4]   2>    "numShards":"2",
>> [junit4:junit4]   2>    "shard":"shard2",
>> [junit4:junit4]   2>    "roles":null,
>> [junit4:junit4]   2>    "state":"down",
>> [junit4:junit4]   2>    "shard_state":"active",
>> [junit4:junit4]   2>    "core":"nodes_used_collection_shard2_replica1",
>> [junit4:junit4]   2>    "collection":"nodes_used_collection",
>> [junit4:junit4]   2>    "shard_range":null,
>> [junit4:junit4]   2>    "node_name":"127.0.0.1:51219_",
>> [junit4:junit4]   2>    "base_url":"http://127.0.0.1:51219"}
>> [junit4:junit4]   2> 412879 T504 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
>> [junit4:junit4]   2> 412879 T499 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
>> [junit4:junit4]   2> 412890 T545 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
>> [junit4:junit4]   2> 412891 T559 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
>> [junit4:junit4]   2> 412891 T517 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
>> [junit4:junit4]   2> 412893 T531 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
>> [junit4:junit4]   2> 412930 T527 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard2_replica2
>> [junit4:junit4]   2> 412931 T527 oasc.ZkController.register Register replica - core:nodes_used_collection_shard2_replica2 address:http://127.0.0.1:51216 collection:nodes_used_collection shard:shard2
>> [junit4:junit4]   2> 412948 T527 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
>> [junit4:junit4]   2> 412982 T527 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard2/election
>> [junit4:junit4]   2> 412991 T511 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard1_replica1
>> [junit4:junit4]   2> 412991 T511 oasc.ZkController.register Register replica - core:nodes_used_collection_shard1_replica1 address:http://127.0.0.1:51213 collection:nodes_used_collection shard:shard1
>> [junit4:junit4]   2> 412997 T511 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard1/election
>> [junit4:junit4]   2> 413002 T541 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard2_replica1
>> [junit4:junit4]   2> 413003 T541 oasc.ZkController.register Register replica - core:nodes_used_collection_shard2_replica1 address:http://127.0.0.1:51219 collection:nodes_used_collection shard:shard2
>> [junit4:junit4]   2> 413005 T541 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard2/election
>> [junit4:junit4]   2> 413052 T511 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
>> [junit4:junit4]   2> 413056 T527 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
>> [junit4:junit4]   2> 413068 T511 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=179999
>> [junit4:junit4]   2> 413080 T527 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
>> [junit4:junit4]   2> 413080 T527 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
>> [junit4:junit4]   2> 413081 T527 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:51216/nodes_used_collection_shard2_replica2/
>> [junit4:junit4]   2> 413099 T527 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&connTimeout=30000&socketTimeout=30000&retry=false
>> [junit4:junit4]   2> 413147 T527 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica2 url=http://127.0.0.1:51216 START replicas=[http://127.0.0.1:51219/nodes_used_collection_shard2_replica1/] nUpdates=100
>> [junit4:junit4]   2> 413150 T527 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica2 url=http://127.0.0.1:51216 DONE.  We have no versions.  sync failed.
>> [junit4:junit4]   2> 413151 T527 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
>> [junit4:junit4]   2> 413151 T527 oasc.ShardLeaderElectionContext.runLeaderProcess We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
>> [junit4:junit4]   2> 413155 T527 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:51216/nodes_used_collection_shard2_replica2/
>> [junit4:junit4]   2> 413156 T527 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leaders/shard2
>> [junit4:junit4]   2> ASYNC  NEW_CORE C24 name=nodes_used_collection_shard2_replica1 org.apache.solr.core.SolrCore@25f07251 url=http://127.0.0.1:51219/nodes_used_collection_shard2_replica1 node=127.0.0.1:51219_ C24_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica1 props:{shard=shard2, state=down, core=nodes_used_collection_shard2_replica1, collection=nodes_used_collection, node_name=127.0.0.1:51219_, base_url=http://127.0.0.1:51219}
>> [junit4:junit4]   2> 413171 T538 C24 P51219 oasc.SolrCore.execute [nodes_used_collection_shard2_replica1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=2
>> [junit4:junit4]   2> 413788 T494 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard1_replica2
>> [junit4:junit4]   2> 413788 T494 oasc.ZkController.register Register replica - core:nodes_used_collection_shard1_replica2 address:http://127.0.0.1:51209 collection:nodes_used_collection shard:shard1
>> [junit4:junit4]   2> 414076 T511 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
>> [junit4:junit4]   2> 414077 T511 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
>> [junit4:junit4]   2> 414077 T511 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:51213/nodes_used_collection_shard1_replica1/
>> [junit4:junit4]   2> 414079 T511 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica1 url=http://127.0.0.1:51213 START replicas=[http://127.0.0.1:51209/nodes_used_collection_shard1_replica2/] nUpdates=100
>> [junit4:junit4]   2> 414084 T511 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica1 url=http://127.0.0.1:51213 DONE.  We have no versions.  sync failed.
>> [junit4:junit4]   2> 414087 T511 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
>> [junit4:junit4]   2> 414089 T511 oasc.ShardLeaderElectionContext.runLeaderProcess We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
>> [junit4:junit4]   2> 414090 T511 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:51213/nodes_used_collection_shard1_replica1/
>> [junit4:junit4]   2> 414090 T511 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leaders/shard1
>> [junit4:junit4]   2> ASYNC  NEW_CORE C25 name=nodes_used_collection_shard1_replica2 org.apache.solr.core.SolrCore@602562c url=http://127.0.0.1:51209/nodes_used_collection_shard1_replica2 node=127.0.0.1:51209_ C25_STATE=coll:nodes_used_collection core:nodes_used_collection_shard1_replica2 props:{shard=shard1, state=down, core=nodes_used_collection_shard1_replica2, collection=nodes_used_collection, node_name=127.0.0.1:51209_, base_url=http://127.0.0.1:51209}
>> [junit4:junit4]   2> 414105 T493 C25 P51209 oasc.SolrCore.execute [nodes_used_collection_shard1_replica2] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
>> [junit4:junit4]   2> 414447 T500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
>> [junit4:junit4]   2> 414528 T545 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
>> [junit4:junit4]   2> 414529 T499 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
>> [junit4:junit4]   2> 414529 T504 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
>> [junit4:junit4]   2> 414529 T559 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
>> [junit4:junit4]   2> 414530 T517 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
>> [junit4:junit4]   2> 414530 T531 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
>> [junit4:junit4]   2> 414563 T541 oasc.ZkController.register We are http://127.0.0.1:51219/nodes_used_collection_shard2_replica1/ and leader is http://127.0.0.1:51216/nodes_used_collection_shard2_replica2/
>> [junit4:junit4]   2> 414563 T541 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard2_replica1 baseURL=http://127.0.0.1:51219
>> [junit4:junit4]   2> 414564 T541 oasc.ZkController.checkRecovery Core needs to recover:nodes_used_collection_shard2_replica1
>> [junit4:junit4]   2> 414564 T541 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
>> [junit4:junit4]   2> 414575 T571 C24 P51219 oasc.RecoveryStrategy.run Starting recovery process.  core=nodes_used_collection_shard2_replica1 recoveringAfterStartup=true
>> [junit4:junit4]   2> 414575 T571 C24 P51219 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
>> [junit4:junit4]   2> 414578 T571 C24 P51219 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica1 state=recovering
>> [junit4:junit4]   2> 414595 T541 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
>> [junit4:junit4]   2> 414596 T527 oasc.ZkController.register We are http://127.0.0.1:51216/nodes_used_collection_shard2_replica2/ and leader is http://127.0.0.1:51216/nodes_used_collection_shard2_replica2/
>> [junit4:junit4]   2> 414596 T527 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard2_replica2 baseURL=http://127.0.0.1:51216
>> [junit4:junit4]   2> 414596 T527 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
>> [junit4:junit4]   2> 414597 T527 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica2 state=active
>> [junit4:junit4]   2> 414599 T511 oasc.ZkController.register We are http://127.0.0.1:51213/nodes_used_collection_shard1_replica1/ and leader is http://127.0.0.1:51213/nodes_used_collection_shard1_replica1/
>> [junit4:junit4]   2> 414599 T511 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard1_replica1 baseURL=http://127.0.0.1:51213
>> [junit4:junit4]   2> 414600 T511 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
>> [junit4:junit4]   2> 414600 T511 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=active
>> [junit4:junit4]   2> 414607 T571 C24 P51219 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
>> [junit4:junit4]   2> 414608 T541 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={numShards=2&shard=shard2&name=nodes_used_collection_shard2_replica1&action=CREATE&collection=nodes_used_collection&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=8859
>> [junit4:junit4]   2> 414634 T511 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
>> [junit4:junit4]   2> 414642 T527 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
>> [junit4:junit4]   2> 414659 T527 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={numShards=2&shard=shard2&name=nodes_used_collection_shard2_replica2&action=CREATE&collection=nodes_used_collection&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=8919
>> [junit4:junit4]   2> 414668 T527 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:51219__nodes_used_collection_shard2_replica1, state: recovering, checkLive: true, onlyIfLeader: true
>> [junit4:junit4]   2> 414670 T511 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={numShards=2&shard=shard1&name=nodes_used_collection_shard1_replica1&action=CREATE&collection=nodes_used_collection&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=8925
>> [junit4:junit4]   2> 414805 T494 oasc.ZkController.register We are http://127.0.0.1:51209/nodes_used_collection_shard1_replica2/ and leader is http://127.0.0.1:51213/nodes_used_collection_shard1_replica1/
>> [junit4:junit4]   2> 414806 T494 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard1_replica2 baseURL=http://127.0.0.1:51209
>> [junit4:junit4]   2> 414806 T494 oasc.ZkController.checkRecovery Core needs to recover:nodes_used_collection_shard1_replica2
>> [junit4:junit4]   2> 414807 T494 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
>> [junit4:junit4]   2> 414809 T572 C25 P51209 oasc.RecoveryStrategy.run Starting recovery process.  core=nodes_used_collection_shard1_replica2 recoveringAfterStartup=true
>> [junit4:junit4]   2> 414810 T572 C25 P51209 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
>> [junit4:junit4]   2> 414812 T572 C25 P51209 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica2 state=recovering
>> [junit4:junit4]   2> 414814 T494 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
>> [junit4:junit4]   2> 414816 T572 C25 P51209 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
>> [junit4:junit4]   2> 414827 T494 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={numShards=2&shard=shard1&name=nodes_used_collection_shard1_replica2&action=CREATE&collection=nodes_used_collection&wt=javabin&qt=/admin/cores&version=2} status=0 QTime=9071
>> [junit4:junit4]   2> 414841 T508 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:51209__nodes_used_collection_shard1_replica2, state: recovering, checkLive: true, onlyIfLeader: true
>> [junit4:junit4]   2> 414842 T501 oasc.OverseerCollectionProcessor.createCollection Finished create command on all shards for collection: nodes_used_collection
>> [junit4:junit4]   2> 414865 T501 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Message id:/overseer/collection-queue-work/qn-0000000000 complete, response:{success={null={responseHeader={status=0,QTime=8859},core=nodes_used_collection_shard2_replica1},null={responseHeader={status=0,QTime=8919},core=nodes_used_collection_shard2_replica2},null={responseHeader={status=0,QTime=8925},core=nodes_used_collection_shard1_replica1},null={responseHeader={status=0,QTime=9071},core=nodes_used_collection_shard1_replica2}}}
>> [junit4:junit4]   2> 414866 T517 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work/qnr-0000000000 state: SyncConnected type NodeDataChanged
>> [junit4:junit4]   2> 414875 T510 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/collections params={numShards=2&name=nodes_used_collection&replicationFactor=2&action=CREATE&wt=javabin&version=2} status=0 QTime=9246
>> [junit4:junit4]   2> 414880 T477 oascsi.HttpClientUtil.createClient Creating new http client, config:
>> [junit4:junit4]   2> 414886 T477 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
>> [junit4:junit4]   2> 414892 T574 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@280c5286 name:ZooKeeperConnection Watcher:127.0.0.1:51206/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
>> [junit4:junit4]   2> 414892 T477 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
>> [junit4:junit4]   2> 414897 T477 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
>> [junit4:junit4]   2> 414908 T477 oascsi.HttpClientUtil.createClient Creating new http client, config:
>> [junit4:junit4]   2> 414911 T477 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
>> [junit4:junit4]   2> 414917 T576 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@29a2c6cf name:ZooKeeperConnection Watcher:127.0.0.1:51206/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
>> [junit4:junit4]   2> 414917 T477 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
>> [junit4:junit4]   2> 414922 T477 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
>> [junit4:junit4]   2> 414961 T524 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=4&maxShardsPerNode=5&name=awholynewcollection_0&replicationFactor=5&action=CREATE&wt=javabin&version=2
>> [junit4:junit4]   2> 414969 T499 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
>> [junit4:junit4]   2> 414974 T501 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000002 message:{
>> [junit4:junit4]   2>    "operation":"createcollection",
>> [junit4:junit4]   2>    "numShards":"4",
>> [junit4:junit4]   2>    "maxShardsPerNode":"5",
>> [junit4:junit4]   2>    "createNodeSet":null,
>> [junit4:junit4]   2>    "name":"awholynewcollection_0",
>> [junit4:junit4]   2>    "replicationFactor":"5"}
>> [junit4:junit4]   2> 414975 T501 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica1 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:51216_
>> [junit4:junit4]   2> 414975 T501 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica2 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:51219_
>> [junit4:junit4]   2> 414975 T501 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica3 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:51222_
>> [junit4:junit4]   2> 414976 T501 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica4 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:51209_
>> [junit4:junit4]   2> 414977 T501 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica5 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:51213_
>> [junit4:junit4]   2> 414980 T501 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica1 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:51216_
>> [junit4:junit4]   2> 414985 T501 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica2 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:51219_
>> [junit4:junit4]   2> 414988 T501 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica3 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:51222_
>> [junit4:junit4]   2> 415002 T526 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876/awholynewcollection_0_shard2_replica1
>> [junit4:junit4]   2> 415003 T526 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
>> [junit4:junit4]   2> 415000 T553 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica3' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369134479435/awholynewcollection_0_shard1_replica3
>> [junit4:junit4]   2> 415004 T553 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
>> [junit4:junit4]   2> 415004 T501 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica4 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:51209_
>> [junit4:junit4]   2> 414999 T525 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876/awholynewcollection_0_shard1_replica1
>> [junit4:junit4]   2> 415005 T525 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
>> [junit4:junit4]   2> 414994 T537 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica2' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/awholynewcollection_0_shard1_replica2
>> [junit4:junit4]   2> 415008 T537 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
>> [junit4:junit4]   2> 414995 T509 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica5' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260/awholynewcollection_0_shard1_replica5
>> [junit4:junit4]   2> 415009 T509 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
>> [junit4:junit4]   2> 414995 T490 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica4' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369134468973/awholynewcollection_0_shard1_replica4
>> [junit4:junit4]   2> 415013 T490 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
>> [junit4:junit4]   2> 415014 T553 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
>> [junit4:junit4]   2> 415014 T553 oasc.ZkController.getConfName Looking for collection configName
>> [junit4:junit4]   2> 415022 T509 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
>> [junit4:junit4]   2> 415025 T509 oasc.ZkController.getConfName Looking for collection configName
>> [junit4:junit4]   2> 415031 T555 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica3' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369134479435/awholynewcollection_0_shard2_replica3
>> [junit4:junit4]   2> 415034 T555 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
>> [junit4:junit4]   2> 415035 T492 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica4' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369134468973/awholynewcollection_0_shard2_replica4
>> [junit4:junit4]   2> 415036 T492 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
>> [junit4:junit4]   2> 415029 T540 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica2' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/awholynewcollection_0_shard2_replica2
>> [junit4:junit4]   2> 415036 T540 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
>> [junit4:junit4]   2> 415038 T537 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
>> [junit4:junit4]   2> 415038 T537 oasc.ZkController.getConfName Looking for collection configName
>> [junit4:junit4]   2> 415039 T553 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
>> [junit4:junit4]   2> 415039 T553 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
>> [junit4:junit4]   2> 415027 T501 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica5 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:51213_
>> [junit4:junit4]   2> 415025 T490 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
>> [junit4:junit4]   2> 415041 T490 oasc.ZkController.getConfName Looking for collection configName
>> [junit4:junit4]   2> 415040 T525 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
>> [junit4:junit4]   2> 415043 T525 oasc.ZkController.getConfName Looking for collection configName
>> [junit4:junit4]   2> 415044 T492 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
>> [junit4:junit4]   2> 415044 T492 oasc.ZkController.getConfName Looking for collection configName
>> [junit4:junit4]   2> 415040 T526 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
>> [junit4:junit4]   2> 415045 T526 oasc.ZkController.getConfName Looking for collection configName
>> [junit4:junit4]   2> 415045 T501 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard3_replica1 as part of slice shard3 of collection awholynewcollection_0 on 127.0.0.1:51216_
>> [junit4:junit4]   2> 415044 T540 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
>> [junit4:junit4]   2> 415073 T540 oasc.ZkController.getConfName Looking for collection configName
>> [junit4:junit4]   2> 415043 T555 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
>> [junit4:junit4]   2> 415074 T555 oasc.ZkController.getConfName Looking for collection configName
>> [junit4:junit4]   2> 415072 T523 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard3_replica1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876/awholynewcollection_0_shard3_replica1
>> [junit4:junit4]   2> 415075 T523 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
>> [junit4:junit4]   2> 415072 T511 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica5' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260/awholynewcollection_0_shard2_replica5
>> [junit4:junit4]   2> 415076 T511 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
>> [junit4:junit4]   2> 415059 T509 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
>> [junit4:junit4]   2> 415080 T509 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
>> [junit4:junit4]   2> 415055 T501 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard3_replica2 as part of slice shard3 of collection awholynewcollection_0 on 127.0.0.1:51219_
>> [junit4:junit4]   2> 415089 T511 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
>> [junit4:junit4]   2> 415089 T537 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
>> [junit4:junit4]   2> 415090 T537 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
>> [junit4:junit4]   2> 415090 T511 oasc.ZkController.getConfName Looking for collection configName
>> [junit4:junit4]   2> 415094 T523 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
>> [junit4:junit4]   2> 415095 T523 oasc.ZkController.getConfName Looking for collection configName
>> [junit4:junit4]   2> 415095 T526 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
>> [junit4:junit4]   2> 415095 T525 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
>> [junit4:junit4]   2> 415097 T526 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
>> [junit4:junit4]   2> 415098 T525 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
>> [junit4:junit4]   2> 415101 T501 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard3_replica3 as part of slice shard3 of collection awholynewcollection_0 on 127.0.0.1:51222_
>> [junit4:junit4]   2> 415107 T539 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard3_replica2' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/awholynewcollection_0_shard3_replica2
>> [junit4:junit4]   2> 415115 T539 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
>> [junit4:junit4]   2> 415104 T490 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
>> [junit4:junit4]   2> 415104 T492 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
>> [junit4:junit4]   2> 415117 T490 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
>> [junit4:junit4]   2> 415121 T550 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard3_replica3' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369134479435/awholynewcollection_0_shard3_replica3
>> [junit4:junit4]   2> 415122 T550 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
>> [junit4:junit4]   2> 415118 T501 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard3_replica4 as part of slice shard3 of collection awholynewcollection_0 on 127.0.0.1:51209_
>> [junit4:junit4]   2> 415123 T492 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
>> [junit4:junit4]   2> 415128 T555 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
>> [junit4:junit4]   2> 415129 T555 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
>> [junit4:junit4]   2> 415130 T501 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard3_replica5 as part of slice shard3 of collection awholynewcollection_0 on 127.0.0.1:51213_
>> [junit4:junit4]   2> 415135 T540 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
>> [junit4:junit4]   2> 415136 T540 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
>> [junit4:junit4]   2> 415140 T523 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
>> [junit4:junit4]   2> 415140 T523 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
>> [junit4:junit4]   2> 415150 T493 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard3_replica4' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369134468973/awholynewcollection_0_shard3_replica4
>> [junit4:junit4]   2> 415153 T493 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
>> [junit4:junit4]   2> 415150 T501 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard4_replica1 as part of slice shard4 of collection awholynewcollection_0 on 127.0.0.1:51216_
>> [junit4:junit4]   2> 415157 T513 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard3_replica5' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260/awholynewcollection_0_shard3_replica5
>> [junit4:junit4]   2> 415163 T513 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
>> [junit4:junit4]   2> 415170 T501 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard4_replica2 as part of slice shard4 of collection awholynewcollection_0 on 127.0.0.1:51219_
>> [junit4:junit4]   2> 415179 T522 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard4_replica1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876/awholynewcollection_0_shard4_replica1
>> [junit4:junit4]   2> 415180 T522 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
>> [junit4:junit4]   2> 415175 T539 oasc.ZkController.createCollectionZkNode Collection zkNode exists
>> [junit4:junit4]   2> 415181 T539 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
>> [junit4:junit4]   2> 415173 T550 oasc.ZkController.createCollectionZkNode Collection zkNode exists
>> [junit4:junit4]   2> 415181 T553 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
>> [junit4:junit4]   2> 415183 T550 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
>> [junit4:junit4]   2> 415186 T511 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
>> [junit4:junit4]   2> 415187 T511 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
>> [junit4:junit4]   2> 415191 T501 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard4_replica3 as part of slice shard4 of collection awholynewcollection_0 on 127.0.0.1:51222_
>> [junit4:junit4]   2> 415195 T513 oasc.ZkController.createCollectionZkNode Collection zkNode exists
>> [junit4:junit4]   2> 415197 T513 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
>> [junit4:junit4]   2> 415195 T493 oasc.ZkController.createCollectionZkNode Collection zkNode exists
>> [junit4:junit4]   2> 415198 T493 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
>> [junit4:junit4]   2> 415194 T509 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
>> [junit4:junit4]   2> 415198 T522 oasc.ZkController.createCollectionZkNode Collection zkNode exists
>> [junit4:junit4]   2> 415200 T522 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
>> [junit4:junit4]   2> 415201 T526 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
>> [junit4:junit4]   2> 415202 T501 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard4_replica4 as part of slice shard4 of collection awholynewcollection_0 on 127.0.0.1:51209_
>> [junit4:junit4]   2> 415209 T537 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
>> [junit4:junit4]   2> 415209 T525 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
>> [junit4:junit4]   2> 415212 T490 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
>> [junit4:junit4]   2> 415218 T540 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
>> [junit4:junit4]   2> 415219 T539 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/awholynewcollection_0_shard3_replica2/'
>> [junit4:junit4]   2> 415222 T555 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
>> [junit4:junit4]   2> 415223 T553 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369134479435/awholynewcollection_0_shard1_replica3/'
>> [junit4:junit4]   2> 415227 T550 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369134479435/awholynewcollection_0_shard3_replica3/'
>> [junit4:junit4]   2> 415228 T492 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
>> [junit4:junit4]   2> 415232 T501 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard4_replica5 as part of slice shard4 of collection awholynewcollection_0 on 127.0.0.1:51213_
>> [junit4:junit4]   2> 415237 T493 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369134468973/awholynewcollection_0_shard3_replica4/'
>> [junit4:junit4]   2> 415237 T513 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260/awholynewcollection_0_shard3_replica5/'
>> [junit4:junit4]   2> 415240 T509 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260/awholynewcollection_0_shard1_replica5/'
>> [junit4:junit4]   2> 415240 T537 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/awholynewcollection_0_shard1_replica2/'
>> [junit4:junit4]   2> 415244 T523 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
>> [junit4:junit4]   2> 415246 T526 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876/awholynewcollection_0_shard2_replica1/'
>> [junit4:junit4]   2> 415245 T522 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876/awholynewcollection_0_shard4_replica1/'
>> [junit4:junit4]   2> 415255 T540 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/awholynewcollection_0_shard2_replica2/'
>> [junit4:junit4]   2> 415256 T492 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369134468973/awholynewcollection_0_shard2_replica4/'
>> [junit4:junit4]   2> 415257 T525 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876/awholynewcollection_0_shard1_replica1/'
>> [junit4:junit4]   2> 415255 T490 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369134468973/awholynewcollection_0_shard1_replica4/'
>> [junit4:junit4]   2> 415268 T511 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
>> [junit4:junit4]   2> 415272 T555 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369134479435/awholynewcollection_0_shard2_replica3/'
>> [junit4:junit4]   2> 415308 T523 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876/awholynewcollection_0_shard3_replica1/'
>> [junit4:junit4]   2> 415322 T536 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard4_replica2' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/awholynewcollection_0_shard4_replica2
>> [junit4:junit4]   2> 415322 T536 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
>> [junit4:junit4]   2> 415323 T551 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard4_replica3' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369134479435/awholynewcollection_0_shard4_replica3
>> [junit4:junit4]   2> 415323 T551 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
>> [junit4:junit4]   2> 415325 T495 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard4_replica4' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369134468973/awholynewcollection_0_shard4_replica4
>> [junit4:junit4]   2> 415325 T495 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
>> [junit4:junit4]   2> 415327 T510 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard4_replica5' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260/awholynewcollection_0_shard4_replica5
>> [junit4:junit4]   2> 415328 T510 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
>> [junit4:junit4]   2> 415337 T511 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260/awholynewcollection_0_shard2_replica5/'
>> [junit4:junit4]   2> 415341 T551 oasc.ZkController.createCollectionZkNode Collection zkNode exists
>> [junit4:junit4]   2> 415342 T551 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
>> [junit4:junit4]   2> 415341 T510 oasc.ZkController.createCollectionZkNode Collection zkNode exists
>> [junit4:junit4]   2> 415343 T510 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
>> [junit4:junit4]   2> 415342 T536 oasc.ZkController.createCollectionZkNode Collection zkNode exists
>> [junit4:junit4]   2> 415343 T536 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
>> [junit4:junit4]   2> 415343 T495 oasc.ZkController.createCollectionZkNode Collection zkNode exists
>> [junit4:junit4]   2> 415345 T495 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
>> [junit4:junit4]   2> 415355 T510 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260/awholynewcollection_0_shard4_replica5/'
>> [junit4:junit4]   2> 415358 T551 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369134479435/awholynewcollection_0_shard4_replica3/'
>> [junit4:junit4]   2> 415359 T536 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/awholynewcollection_0_shard4_replica2/'
>> [junit4:junit4]   2> 415390 T495 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369134468973/awholynewcollection_0_shard4_replica4/'
>> [junit4:junit4]   2> 415879 T513 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
>> [junit4:junit4]   2> 416060 T526 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
>> [junit4:junit4]   2> 416068 T523 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
>> [junit4:junit4]   2> 416129 T537 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
>> [junit4:junit4]   2> 416174 T490 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
>> [junit4:junit4]   2> 416180 T500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
>> [junit4:junit4]   2> 416182 T500 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
>> [junit4:junit4]   2>    "operation":"state",
>> [junit4:junit4]   2>    "core_node_name":"127.0.0.1:51219__nodes_used_collection_shard2_replica1",
>> [junit4:junit4]   2>    "numShards":"2",
>> [junit4:junit4]   2>    "shard":"shard2",
>> [junit4:junit4]   2>    "roles":null,
>> [junit4:junit4]   2>    "state":"recovering",
>> [junit4:junit4]   2>    "shard_state":"active",
>> [junit4:junit4]   2>    "core":"nodes_used_collection_shard2_replica1",
>> [junit4:junit4]   2>    "collection":"nodes_used_collection",
>> [junit4:junit4]   2>    "shard_range":null,
>> [junit4:junit4]   2>    "node_name":"127.0.0.1:51219_",
>> [junit4:junit4]   2>    "base_url":"http://127.0.0.1:51219"}
>> [junit4:junit4]   2> 416231 T500 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
>> [junit4:junit4]   2>    "operation":"state",
>> [junit4:junit4]   2>    "core_node_name":"127.0.0.1:51216__nodes_used_collection_shard2_replica2",
>> [junit4:junit4]   2>    "numShards":"2",
>> [junit4:junit4]   2>    "shard":"shard2",
>> [junit4:junit4]   2>    "roles":null,
>> [junit4:junit4]   2>    "state":"active",
>> [junit4:junit4]   2>    "shard_state":"active",
>> [junit4:junit4]   2>    "core":"nodes_used_collection_shard2_replica2",
>> [junit4:junit4]   2>    "collection":"nodes_used_collection",
>> [junit4:junit4]   2>    "shard_range":null,
>> [junit4:junit4]   2>    "node_name":"127.0.0.1:51216_",
>> [junit4:junit4]   2>    "base_url":"http://127.0.0.1:51216"}
>> [junit4:junit4]   2> 416232 T510 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
>> [junit4:junit4]   2> 416259 T555 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
>> [junit4:junit4]   2> 416272 T500 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
>> [junit4:junit4]   2>    "operation":"state",
>> [junit4:junit4]   2>    "core_node_name":"127.0.0.1:51213__nodes_used_collection_shard1_replica1",
>> [junit4:junit4]   2>    "numShards":"2",
>> [junit4:junit4]   2>    "shard":"shard1",
>> [junit4:junit4]   2>    "roles":null,
>> [junit4:junit4]   2>    "state":"active",
>> [junit4:junit4]   2>    "shard_state":"active",
>> [junit4:junit4]   2>    "core":"nodes_used_collection_shard1_replica1",
>> [junit4:junit4]   2>    "collection":"nodes_used_collection",
>> [junit4:junit4]   2>    "shard_range":null,
>> [junit4:junit4]   2>    "node_name":"127.0.0.1:51213_",
>> [junit4:junit4]   2>    "base_url":"http://127.0.0.1:51213"}
>> [junit4:junit4]   2> 416326 T500 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
>> [junit4:junit4]   2>    "operation":"state",
>> [junit4:junit4]   2>    "core_node_name":"127.0.0.1:51209__nodes_used_collection_shard1_replica2",
>> [junit4:junit4]   2>    "numShards":"2",
>> [junit4:junit4]   2>    "shard":"shard1",
>> [junit4:junit4]   2>    "roles":null,
>> [junit4:junit4]   2>    "state":"recovering",
>> [junit4:junit4]   2>    "shard_state":"active",
>> [junit4:junit4]   2>    "core":"nodes_used_collection_shard1_replica2",
>> [junit4:junit4]   2>    "collection":"nodes_used_collection",
>> [junit4:junit4]   2>    "shard_range":null,
>> [junit4:junit4]   2>    "node_name":"127.0.0.1:51209_",
>> [junit4:junit4]   2>    "base_url":"http://127.0.0.1:51209"}
>> [junit4:junit4]   2> 416437 T576 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
>> [junit4:junit4]   2> 416439 T574 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
>> [junit4:junit4]   2> 416437 T531 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
>> [junit4:junit4]   2> 416453 T545 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
>> [junit4:junit4]   2> 416453 T517 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
>> [junit4:junit4]   2> 416451 T559 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
>> [junit4:junit4]   2> 416444 T504 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
>> [junit4:junit4]   2> 416443 T499 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
>> [junit4:junit4]   2> 416550 T493 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
>> [junit4:junit4]   2> 416601 T525 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
>> [junit4:junit4]   2> 416611 T509 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
>> [junit4:junit4]   2> 416671 T527 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:51219__nodes_used_collection_shard2_replica1, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
>> [junit4:junit4]   2> 416684 T527 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:51219__nodes_used_collection_shard2_replica1&state=recovering&nodeName=127.0.0.1:51219_&action=PREPRECOVERY&checkLive=true&core=nodes_used_collection_shard2_replica2&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2017
>> [junit4:junit4]   2> 416770 T551 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
>> [junit4:junit4]   2> 416787 T553 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
>> [junit4:junit4]   2> 416825 T522 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
>> [junit4:junit4]   2> 416864 T508 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:51209__nodes_used_collection_shard1_replica2, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
>> [junit4:junit4]   2> 416865 T508 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:51209__nodes_used_collection_shard1_replica2&state=recovering&nodeName=127.0.0.1:51209_&action=PREPRECOVERY&checkLive=true&core=nodes_used_collection_shard1_replica1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2024
>> [junit4:junit4]   2> 416873 T536 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
>> [junit4:junit4]   2> 416892 T495 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
>> [junit4:junit4]   2> 416979 T540 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
>> [junit4:junit4]   2> 417171 T492 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
>> [junit4:junit4]   2> 417417 T513 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
>> [junit4:junit4]   2> 417446 T513 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
>> [junit4:junit4]   2> 417455 T539 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
>> [junit4:junit4]   2> 417469 T550 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
>> [junit4:junit4]   2> 417507 T511 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
>> [junit4:junit4]   2> 417545 T526 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
>> [junit4:junit4]   2> 417568 T526 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
>> [junit4:junit4]   2> 417626 T513 oass.IndexSchema.readSchema [awholynewcollection_0_shard3_replica5] Schema name=test
>> [junit4:junit4]   2> 417836 T490 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
>> [junit4:junit4]   2> 417839 T526 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica1] Schema name=test
>> [junit4:junit4]   2> 417883 T490 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
>> [junit4:junit4]   2> 417888 T537 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
>> [junit4:junit4]   2> 417903 T537 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
>> [junit4:junit4]   2> 417948 T555 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
>> [junit4:junit4]   2> 417966 T555 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
>> [junit4:junit4]   2> 417978 T537 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica2] Schema name=test
>> [junit4:junit4]   2> 418101 T555 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica3] Schema name=test
>> [junit4:junit4]   2> 418129 T523 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
>> [junit4:junit4]   2> 418142 T490 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica4] Schema name=test
>> [junit4:junit4]   2> 418155 T523 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
>> [junit4:junit4]   2> 418179 T493 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
>> [junit4:junit4]   2> 418215 T493 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
>> [junit4:junit4]   2> 418268 T495 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
>> [junit4:junit4]   2> 418273 T495 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
>> [junit4:junit4]   2> 418374 T493 oass.IndexSchema.readSchema [awholynewcollection_0_shard3_replica4] Schema name=test
>> [junit4:junit4]   2> 418490 T523 oass.IndexSchema.readSchema [awholynewcollection_0_shard3_replica1] Schema name=test
>> [junit4:junit4]   2> 418588 T525 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
>> [junit4:junit4]   2> 418589 T495 oass.IndexSchema.readSchema [awholynewcollection_0_shard4_replica4] Schema name=test
>> [junit4:junit4]   2> 418630 T510 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
>> [junit4:junit4]   2> 418636 T525 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
>> [junit4:junit4]   2> 418645 T510 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
>> [junit4:junit4]   2> 418661 T510 oass.IndexSchema.readSchema [awholynewcollection_0_shard4_replica5] Schema name=test
>> [junit4:junit4]   2> 418676 T525 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica1] Schema name=test
>> [junit4:junit4]   2>  C24_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica1 props:{shard=shard2, state=recovering, core=nodes_used_collection_shard2_replica1, collection=nodes_used_collection, node_name=127.0.0.1:51219_, base_url=http://127.0.0.1:51219}
>> [junit4:junit4]   2> 418697 T571 C24 P51219 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:51216/nodes_used_collection_shard2_replica2/ core=nodes_used_collection_shard2_replica1 - recoveringAfterStartup=true
>> [junit4:junit4]   2> 418708 T571 C24 P51219 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica1 url=http://127.0.0.1:51219 START replicas=[http://127.0.0.1:51216/nodes_used_collection_shard2_replica2/] nUpdates=100
>> [junit4:junit4]   2> 418708 T571 C24 P51219 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
>> [junit4:junit4]   2> 418709 T571 C24 P51219 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=nodes_used_collection_shard2_replica1
>> [junit4:junit4]   2> 418709 T571 C24 P51219 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=nodes_used_collection_shard2_replica1
>> [junit4:junit4]   2> 418709 T571 C24 P51219 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=nodes_used_collection_shard2_replica1
>> [junit4:junit4]   2> 418710 T571 C24 P51219 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
>> [junit4:junit4]   2> 418710 T571 C24 P51219 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:51216/nodes_used_collection_shard2_replica2/. core=nodes_used_collection_shard2_replica1
>> [junit4:junit4]   2> 418710 T571 C24 P51219 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
>> [junit4:junit4]   2> 418800 T511 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
>> [junit4:junit4]   2> 418819 T522 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
>> [junit4:junit4]   2> 418821 T511 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
>> [junit4:junit4]   2> 418835 T522 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
>> [junit4:junit4]   2> 418851 T509 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
>> [junit4:junit4]   2> ASYNC  NEW_CORE C26 name=nodes_used_collection_shard2_replica2 org.apache.solr.core.SolrCore@17dec27a url=http://127.0.0.1:51216/nodes_used_collection_shard2_replica2 node=127.0.0.1:51216_ C26_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica2 props:{shard=shard2, state=active, core=nodes_used_collection_shard2_replica2, collection=nodes_used_collection, node_name=127.0.0.1:51216_, base_url=http://127.0.0.1:51216, leader=true}
>> [junit4:junit4]   2> 418867 T527 C26 P51216 oasc.SolrCore.execute [nodes_used_collection_shard2_replica2] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
>> [junit4:junit4]   2>  C25_STATE=coll:nodes_used_collection core:nodes_used_collection_shard1_replica2 props:{shard=shard1, state=recovering, core=nodes_used_collection_shard1_replica2, collection=nodes_used_collection, node_name=127.0.0.1:51209_, base_url=http://127.0.0.1:51209}
>> [junit4:junit4]   2> 418867 T572 C25 P51209 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:51213/nodes_used_collection_shard1_replica1/ core=nodes_used_collection_shard1_replica2 - recoveringAfterStartup=true
>> [junit4:junit4]   2> 418868 T572 C25 P51209 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica2 url=http://127.0.0.1:51209 START replicas=[http://127.0.0.1:51213/nodes_used_collection_shard1_replica1/] nUpdates=100
>> [junit4:junit4]   2> 418879 T572 C25 P51209 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
>> [junit4:junit4]   2> 418879 T572 C25 P51209 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=nodes_used_collection_shard1_replica2
>> [junit4:junit4]   2> 418880 T572 C25 P51209 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=nodes_used_collection_shard1_replica2
>> [junit4:junit4]   2> 418880 T572 C25 P51209 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=nodes_used_collection_shard1_replica2
>> [junit4:junit4]   2> 418880 T572 C25 P51209 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
>> [junit4:junit4]   2> 418880 T572 C25 P51209 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:51213/nodes_used_collection_shard1_replica1/. core=nodes_used_collection_shard1_replica2
>> [junit4:junit4]   2> 418881 T572 C25 P51209 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
>> [junit4:junit4]   2> 418910 T509 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
>> [junit4:junit4]   2> 418919 T509 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica5] Schema name=test
>> [junit4:junit4]   2> 418995 T492 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
>> [junit4:junit4]   2> 419012 T492 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
>> [junit4:junit4]   2> ASYNC  NEW_CORE C27 name=nodes_used_collection_shard1_replica1 org.apache.solr.core.SolrCore@4a2ec873 url=http://127.0.0.1:51213/nodes_used_collection_shard1_replica1 node=127.0.0.1:51213_ C27_STATE=coll:nodes_used_collection core:nodes_used_collection_shard1_replica1 props:{shard=shard1, state=active, core=nodes_used_collection_shard1_replica1, collection=nodes_used_collection, node_name=127.0.0.1:51213_, base_url=http://127.0.0.1:51213, leader=true}
>> [junit4:junit4]   2> 419024 T512 C27 P51213 oasc.SolrCore.execute [nodes_used_collection_shard1_replica1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=5
>> [junit4:junit4]   2> 419059 T511 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica5] Schema name=test
>> [junit4:junit4]   2> 419083 T553 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
>> [junit4:junit4]   2> 419104 T522 oass.IndexSchema.readSchema [awholynewcollection_0_shard4_replica1] Schema name=test
>> [junit4:junit4]   2> 419115 T553 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
>> [junit4:junit4]   2> 419141 T553 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica3] Schema name=test
>> [junit4:junit4]   2> 419313 T512 C27 P51213 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
>> [junit4:junit4]   2> 419341 T551 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
>> [junit4:junit4]   2> 419357 T551 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
>> [junit4:junit4]   2> 419364 T551 oass.IndexSchema.readSchema [awholynewcollection_0_shard4_replica3] Schema name=test
>> [junit4:junit4]   2> 419391 T527 C26 P51216 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
>> [junit4:junit4]   2> 419418 T540 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
>> [junit4:junit4]   2> 419459 T540 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
>> [junit4:junit4]   2> 419468 T540 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica2] Schema name=test
>> [junit4:junit4]   2> 419493 T527 C26 P51216 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
>> [junit4:junit4]   2>          commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@43b9d518 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4b06504d),segFN=segments_1,generation=1}
>> [junit4:junit4]   2> 419494 T527 C26 P51216 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
>> [junit4:junit4]   2> 419502 T536 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
>> [junit4:junit4]   2> 419526 T536 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
>> [junit4:junit4]   2> 419552 T527 C26 P51216 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
>> [junit4:junit4]   2>          commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@43b9d518 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4b06504d),segFN=segments_1,generation=1}
>> [junit4:junit4]   2>          commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@43b9d518 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4b06504d),segFN=segments_2,generation=2}
>> [junit4:junit4]   2> 419552 T527 C26 P51216 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
>> [junit4:junit4]   2> 419564 T550 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
>> [junit4:junit4]   2> 419588 T492 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica4] Schema name=test
>> [junit4:junit4]   2> 419594 T527 C26 P51216 oass.SolrIndexSearcher.<init> Opening Searcher@19431b0b realtime
>> [junit4:junit4]   2> 419596 T527 C26 P51216 oasu.DirectUpdateHandler2.commit end_commit_flush
>> [junit4:junit4]   2> 419596 T527 C26 P51216 oasup.LogUpdateProcessor.finish [nodes_used_collection_shard2_replica2] webapp= path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 568
>> [junit4:junit4]   2> 419598 T550 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
>> [junit4:junit4]   2> 419760 T539 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
>> [junit4:junit4]   2> 419787 T539 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
>> [junit4:junit4]   2> 419792 T536 oass.IndexSchema.readSchema [awholynewcollection_0_shard4_replica2] Schema name=test
>> [junit4:junit4]   2> 419799 T512 C27 P51213 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
>> [junit4:junit4]   2>          commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2f36a361 lockFactory=org.apache.lucene.store.NativeFSLockFactory@646cb8c7),segFN=segments_1,generation=1}
>> [junit4:junit4]   2> 419808 T512 C27 P51213 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
>> [junit4:junit4]   2> 419813 T539 oass.IndexSchema.readSchema [awholynewcollection_0_shard3_replica2] Schema name=test
>> [junit4:junit4]   2> 419842 T512 C27 P51213 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
>> [junit4:junit4]   2>          commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2f36a361 lockFactory=org.apache.lucene.store.NativeFSLockFactory@646cb8c7),segFN=segments_1,generation=1}
>> [junit4:junit4]   2>          commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2f36a361 lockFactory=org.apache.lucene.store.NativeFSLockFactory@646cb8c7),segFN=segments_2,generation=2}
>> [junit4:junit4]   2> 419842 T512 C27 P51213 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
>> [junit4:junit4]   2> 419843 T512 C27 P51213 oass.SolrIndexSearcher.<init> Opening Searcher@1a11ad83 realtime
>> [junit4:junit4]   2> 419844 T512 C27 P51213 oasu.DirectUpdateHandler2.commit end_commit_flush
>> [junit4:junit4]   2> 419844 T512 C27 P51213 oasup.LogUpdateProcessor.finish [nodes_used_collection_shard1_replica1] webapp= path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 748
>> [junit4:junit4]   2> 420208 T550 oass.IndexSchema.readSchema [awholynewcollection_0_shard3_replica3] Schema name=test
>> [junit4:junit4]   2> 421740 T571 C24 P51219 oash.ReplicationHandler.inform Commits will be reserved for  10000
>> [junit4:junit4]   2> 421741 T571 C24 P51219 oascsi.HttpClientUtil.createClient Creating new http client, config:connTimeout=5000&socketTimeout=20000&allowCompression=false&maxConnections=10000&maxConnectionsPerHost=10000
>> [junit4:junit4]   2> 421747 T572 C25 P51209 oash.ReplicationHandler.inform Commits will be reserved for  10000
>> [junit4:junit4]   2> 422081 T571 C24 P51219 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
>> [junit4:junit4]   2> 422081 T572 C25 P51209 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
>> [junit4:junit4]   2> 422139 T527 C26 P51216 oash.ReplicationHandler.inform Commits will be reserved for  10000
>> [junit4:junit4]   2> 422139 T527 C26 P51216 oasc.SolrCore.execute [nodes_used_collection_shard2_replica2] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1
>> [junit4:junit4]   2> 422141 T571 C24 P51219 oash.SnapPuller.fetchLatestIndex Master's generation: 2
>> [junit4:junit4]   2> 422142 T571 C24 P51219 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
>> [junit4:junit4]   2> 422142 T571 C24 P51219 oash.SnapPuller.fetchLatestIndex Starting replication process
>> [junit4:junit4]   2> 422158 T508 C27 P51213 oash.ReplicationHandler.inform Commits will be reserved for  10000
>> [junit4:junit4]   2> 422158 T508 C27 P51213 oasc.SolrCore.execute [nodes_used_collection_shard1_replica1] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=27
>> [junit4:junit4]   2> 422165 T572 C25 P51209 oash.SnapPuller.fetchLatestIndex Master's generation: 2
>> [junit4:junit4]   2> 422166 T572 C25 P51209 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
>> [junit4:junit4]   2> 422166 T572 C25 P51209 oash.SnapPuller.fetchLatestIndex Starting replication process
>> [junit4:junit4]   2> 422173 T512 C27 P51213 oasc.SolrCore.execute [nodes_used_collection_shard1_replica1] webapp= path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=3
>> [junit4:junit4]   2> 422174 T572 C25 P51209 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
>> [junit4:junit4]   2> 422194 T572 C25 P51209 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369134468973/nodes_used_collection_shard1_replica2/data/index.20130521070818828
>> [junit4:junit4]   2> 422195 T594 C26 P51216 oasc.SolrCore.execute [nodes_used_collection_shard2_replica2] webapp= path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=23
>> [junit4:junit4]   2> 422197 T571 C24 P51219 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
>> [junit4:junit4]   2> 422197 T572 C25 P51209 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@231824d lockFactory=org.apache.lucene.store.NativeFSLockFactory@263676bd) fullCopy=false
>> [junit4:junit4]   2> 422206 T571 C24 P51219 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/nodes_used_collection_shard2_replica1/data/index.20130521070818850
>> [junit4:junit4]   2> 422207 T571 C24 P51219 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@29a81175 lockFactory=org.apache.lucene.store.NativeFSLockFactory@354e3bce) fullCopy=false
>> [junit4:junit4]   2> 422308 T508 C27 P51213 oasc.SolrCore.execute [nodes_used_collection_shard1_replica1] webapp= path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=11
>> [junit4:junit4]   2> 422349 T527 C26 P51216 oasc.SolrCore.execute [nodes_used_collection_shard2_replica2] webapp= path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
>> [junit4:junit4]   2> 422490 T571 C24 P51219 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
>> [junit4:junit4]   2> 422501 T572 C25 P51209 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
>> [junit4:junit4]   2> 422579 T571 C24 P51219 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
>> [junit4:junit4]   2> 422579 T571 C24 P51219 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=nodes_used_collection_shard2_replica1
>> [junit4:junit4]   2> 422592 T572 C25 P51209 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
>> [junit4:junit4]   2> 422605 T572 C25 P51209 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=nodes_used_collection_shard1_replica2
>> [junit4:junit4]   2> 422760 T571 C24 P51219 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
>> [junit4:junit4]   2>          commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3f65a49 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4da90726),segFN=segments_1,generation=1}
>> [junit4:junit4]   2>          commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3f65a49 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4da90726),segFN=segments_2,generation=2}
>> [junit4:junit4]   2> 422771 T571 C24 P51219 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
>> [junit4:junit4]   2> 422779 T571 C24 P51219 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
>> [junit4:junit4]   2> 422783 T571 C24 P51219 oass.SolrIndexSearcher.<init> Opening Searcher@5bac7081 main
>> [junit4:junit4]   2> 422785 T568 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica1] Registered new searcher Searcher@5bac7081 main{StandardDirectoryReader(segments_2:1:nrt)}
>> [junit4:junit4]   2> 422787 T571 C24 P51219 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/nodes_used_collection_shard2_replica1/data/index.20130521070818850 [CachedDir<<refCount=0;path=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/nodes_used_collection_shard2_replica1/data/index.20130521070818850;done=true>>]
>> [junit4:junit4]   2> 422787 T571 C24 P51219 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/nodes_used_collection_shard2_replica1/data/index.20130521070818850
>> [junit4:junit4]   2> 422804 T571 C24 P51219 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/nodes_used_collection_shard2_replica1/data/index.20130521070818850
>> [junit4:junit4]   2> 422805 T571 C24 P51219 oasc.RecoveryStrategy.replay No replay needed. core=nodes_used_collection_shard2_replica1
>> [junit4:junit4]   2> 422805 T571 C24 P51219 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=nodes_used_collection_shard2_replica1
>> [junit4:junit4]   2> 422805 T571 C24 P51219 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica1 state=active
>> [junit4:junit4]   2> 422893 T571 C24 P51219 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=nodes_used_collection_shard2_replica1
>> [junit4:junit4]   2> 422964 T572 C25 P51209 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
>> [junit4:junit4]   2>          commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@a44eeb7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@5164bc93),segFN=segments_1,generation=1}
>> [junit4:junit4]   2>          commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@a44eeb7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@5164bc93),segFN=segments_2,generation=2}
>> [junit4:junit4]   2> 422982 T572 C25 P51209 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
>> [junit4:junit4]   2> 423006 T572 C25 P51209 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
>> [junit4:junit4]   2> 423017 T572 C25 P51209 oass.SolrIndexSearcher.<init> Opening Searcher@23f3a36a main
>> [junit4:junit4]   2> 423020 T565 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica2] Registered new searcher Searcher@23f3a36a main{StandardDirectoryReader(segments_2:1:nrt)}
>> [junit4:junit4]   2> 423027 T572 C25 P51209 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369134468973/nodes_used_collection_shard1_replica2/data/index.20130521070818828 [CachedDir<<refCount=0;path=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369134468973/nodes_used_collection_shard1_replica2/data/index.20130521070818828;done=true>>]
>> [junit4:junit4]   2> 423030 T572 C25 P51209 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369134468973/nodes_used_collection_shard1_replica2/data/index.20130521070818828
>> [junit4:junit4]   2> 423031 T572 C25 P51209 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369134468973/nodes_used_collection_shard1_replica2/data/index.20130521070818828
>> [junit4:junit4]   2> 423033 T572 C25 P51209 oasc.RecoveryStrategy.replay No replay needed. core=nodes_used_collection_shard1_replica2
>> [junit4:junit4]   2> 423033 T572 C25 P51209 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=nodes_used_collection_shard1_replica2
>> [junit4:junit4]   2> 423035 T572 C25 P51209 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica2 state=active
>> [junit4:junit4]   2> 423077 T572 C25 P51209 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=nodes_used_collection_shard1_replica2
>> [junit4:junit4]   2> 423204 T500 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
>> [junit4:junit4]   2> 423219 T500 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
>> [junit4:junit4]   2>    "operation":"state",
>> [junit4:junit4]   2>    "core_node_name":"127.0.0.1:51219__nodes_used_collection_shard2_replica1",
>> [junit4:junit4]   2>    "numShards":"2",
>> [junit4:junit4]   2>    "shard":"shard2",
>> [junit4:junit4]   2>    "roles":null,
>> [junit4:junit4]   2>    "state":"active",
>> [junit4:junit4]   2>    "shard_state":"active",
>> [junit4:junit4]   2>    "core":"nodes_used_collection_shard2_replica1",
>> [junit4:junit4]   2>    "collection":"nodes_used_collection",
>> [junit4:junit4]   2>    "shard_range":null,
>> [junit4:junit4]   2>    "node_name":"127.0.0.1:51219_",
>> [junit4:junit4]   2>    "base_url":"http://127.0.0.1:51219"}
>> [junit4:junit4]   2> 423239 T500 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
>> [junit4:junit4]   2>    "operation":"state",
>> [junit4:junit4]   2>    "core_node_name":"127.0.0.1:51209__nodes_used_collection_shard1_replica2",
>> [junit4:junit4]   2>    "numShards":"2",
>> [junit4:junit4]   2>    "shard":"shard1",
>> [junit4:junit4]   2>    "roles":null,
>> [junit4:junit4]   2>    "state":"active",
>> [junit4:junit4]   2>    "shard_state":"active",
>> [junit4:junit4]   2>    "core":"nodes_used_collection_shard1_replica2",
>> [junit4:junit4]   2>    "collection":"nodes_used_collection",
>> [junit4:junit4]   2>    "shard_range":null,
>> [junit4:junit4]   2>    "node_name":"127.0.0.1:51209_",
>> [junit4:junit4]   2>    "base_url":"http://127.0.0.1:51209"}
>> [junit4:junit4]   2> 423265 T576 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
>> [junit4:junit4]   2> 423265 T531 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
>> [junit4:junit4]   2> 423265 T499 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
>> [junit4:junit4]   2> 423266 T559 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
>> [junit4:junit4]   2> 423265 T574 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
>> [junit4:junit4]   2> 423266 T517 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
>> [junit4:junit4]   2> 423265 T504 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
>> [junit4:junit4]   2> 423265 T545 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
>> [junit4:junit4]   2> 436091 T536 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
>> [junit4:junit4]   2> 436359 T513 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
>> [junit4:junit4]   2> 436433 T536 oass.IndexSchema.readSchema default search field in schema is text
>> [junit4:junit4]   2> 436439 T536 oass.IndexSchema.readSchema unique key field: id
>> [junit4:junit4]   2> 436522 T513 oass.IndexSchema.readSchema default search field in schema is text
>> [junit4:junit4]   2> 436528 T513 oass.IndexSchema.readSchema unique key field: id
>> [junit4:junit4]   2> 436707 T537 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
>> [junit4:junit4]   2> 436758 T536 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
>> [junit4:junit4]   2> 436868 T522 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
>> [junit4:junit4]   2> 436888 T522 oass.IndexSchema.readSchema default search field in schema is text
>> [junit4:junit4]   2> 436892 T522 oass.IndexSchema.readSchema unique key field: id
>> [junit4:junit4]   2> 436920 T537 oass.IndexSchema.readSchema default search field in schema is text
>> [junit4:junit4]   2> 436927 T537 oass.IndexSchema.readSchema unique key field: id
>> [junit4:junit4]   2> 436997 T495 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
>> [junit4:junit4]   2> 437038 T526 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
>> [junit4:junit4]   2> 437059 T536 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
>> [junit4:junit4]   2> 437187 T495 oass.IndexSchema.readSchema default search field in schema is text
>> [junit4:junit4]   2> 437193 T526 oass.IndexSchema.readSchema default search field in schema is text
>> [junit4:junit4]   2> 437199 T526 oass.IndexSchema.readSchema unique key field: id
>> [junit4:junit4]   2> 437228 T493 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
>> [junit4:junit4]   2> 437279 T555 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
>> [junit4:junit4]   2> 437294 T510 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
>> [junit4:junit4]   2> 437329 T513 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
>> [junit4:junit4]   2> 437339 T555 oass.IndexSchema.readSchema default search field in schema is text
>> [junit4:junit4]   2> 437413 T553 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
>> [junit4:junit4]   2> 437414 T495 oass.IndexSchema.readSchema unique key field: id
>> [junit4:junit4]   2> 437495 T510 oass.IndexSchema.readSchema default search field in schema is text
>> [junit4:junit4]   2> 437502 T513 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
>> [junit4:junit4]   2> 437520 T513 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
>> [junit4:junit4]   2> 437522 T536 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
>> [junit4:junit4]   2> 437529 T510 oass.IndexSchema.readSchema unique key field: id
>> [junit4:junit4]   2> 437544 T513 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
>> [junit4:junit4]   2> 437545 T513 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
>> [junit4:junit4]   2> 437545 T513 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
>> [junit4:junit4]   2> 437551 T513 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
>> [junit4:junit4]   2> 437552 T513 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
>> [junit4:junit4]   2> 437552 T513 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
>> [junit4:junit4]   2> 437553 T513 oasc.SolrCore.<init> [awholynewcollection_0_shard3_replica5] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260/awholynewcollection_0_shard3_replica5/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260/awholynewcollection_0_shard3_replica5/data/
>> [junit4:junit4]   2> 437554 T513 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3248f37e
>> [junit4:junit4]   2> 437555 T513 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
>> [junit4:junit4]   2> 437557 T537 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
>> [junit4:junit4]   2> 437567 T522 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
>> [junit4:junit4]   2> 437580 T522 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
>> [junit4:junit4]   2> 437585 T493 oass.IndexSchema.readSchema default search field in schema is text
>> [junit4:junit4]   2> 437590 T493 oass.IndexSchema.readSchema unique key field: id
>> [junit4:junit4]   2> 437596 T511 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
>> [junit4:junit4]   2> 437596 T522 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
>> [junit4:junit4]   2> 437604 T536 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
>> [junit4:junit4]   2> 437605 T536 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
>> [junit4:junit4]   2> 437605 T536 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
>> [junit4:junit4]   2> 437605 T522 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
>> [junit4:junit4]   2> 437607 T522 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
>> [junit4:junit4]   2> 437607 T522 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
>> [junit4:junit4]   2> 437606 T526 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
>> [junit4:junit4]   2> 437619 T537 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
>> [junit4:junit4]   2> 437625 T522 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
>> [junit4:junit4]   2> 437625 T522 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
>> [junit4:junit4]   2> 437626 T522 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
>> [junit4:junit4]   2> 437626 T522 oasc.SolrCore.<init> [awholynewcollection_0_shard4_replica1] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876/awholynewcollection_0_shard4_replica1/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876/awholynewcollection_0_shard4_replica1/data/
>> [junit4:junit4]   2> 437627 T522 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3248f37e
>> [junit4:junit4]   2> 437628 T522 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
>> [junit4:junit4]   2> 437630 T513 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260/awholynewcollection_0_shard3_replica5/data
>> [junit4:junit4]   2> 437630 T513 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260/awholynewcollection_0_shard3_replica5/data/index/
>> [junit4:junit4]   2> 437630 T513 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard3_replica5] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260/awholynewcollection_0_shard3_replica5/data/index' doesn't exist. Creating new index...
>> [junit4:junit4]   2> 437633 T553 oass.IndexSchema.readSchema default search field in schema is text
>> [junit4:junit4]   2> 437638 T553 oass.IndexSchema.readSchema unique key field: id
>> [junit4:junit4]   2> 437627 T536 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
>> [junit4:junit4]   2> 437639 T536 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
>> [junit4:junit4]   2> 437640 T536 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
>> [junit4:junit4]   2> 437640 T536 oasc.SolrCore.<init> [awholynewcollection_0_shard4_replica2] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/awholynewcollection_0_shard4_replica2/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/awholynewcollection_0_shard4_replica2/data/
>> [junit4:junit4]   2> 437641 T536 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3248f37e
>> [junit4:junit4]   2> 437641 T536 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
>> [junit4:junit4]   2> 437643 T522 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876/awholynewcollection_0_shard4_replica1/data
>> [junit4:junit4]   2> 437643 T522 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876/awholynewcollection_0_shard4_replica1/data/index/
>> [junit4:junit4]   2> 437644 T522 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard4_replica1] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876/awholynewcollection_0_shard4_replica1/data/index' doesn't exist. Creating new index...
>> [junit4:junit4]   2> 437654 T536 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/awholynewcollection_0_shard4_replica2/data
>> [junit4:junit4]   2> 437655 T522 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369134473876/awholynewcollection_0_shard4_replica1/data/index
>> [junit4:junit4]   2> 437654 T513 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369134471260/awholynewcollection_0_shard3_replica5/data/index
>> [junit4:junit4]   2> 437655 T536 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/awholynewcollection_0_shard4_replica2/data/index/
>> [junit4:junit4]   2> 437657 T536 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard4_replica2] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/awholynewcollection_0_shard4_replica2/data/index' doesn't exist. Creating new index...
>> [junit4:junit4]   2> 437665 T555 oass.IndexSchema.readSchema unique key field: id
>> [junit4:junit4]   2> 437668 T536 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/awholynewcollection_0_shard4_replica2/data/index
>> [junit4:junit4]   2> 437676 T526 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
>> [junit4:junit4]   2> 437721 T537 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
>> [junit4:junit4]   2> 437728 T511 oass.IndexSchema.readSchema default search field in schema is text
>> [junit4:junit4]   2> 437733 T511 oass.IndexSchema.readSchema unique key field: id
>> [junit4:junit4]   2> 437738 T537 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
>> [junit4:junit4]   2> 437739 T537 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
>> [junit4:junit4]   2> 437740 T537 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
>> [junit4:junit4]   2> 437750 T537 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
>> [junit4:junit4]   2> 437752 T537 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
>> [junit4:junit4]   2> 437753 T537 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
>> [junit4:junit4]   2> 437755 T537 oasc.SolrCore.<init> [awholynewcollection_0_shard1_replica2] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/awholynewcollection_0_shard1_replica2/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/awholynewcollection_0_shard1_replica2/data/
>> [junit4:junit4]   2> 437755 T537 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3248f37e
>> [junit4:junit4]   2> 437756 T537 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
>> [junit4:junit4]   2> 437758 T536 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
>> [junit4:junit4]   2>          commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7e386bc lockFactory=org.apache.lucene.store.NativeFSLockFactory@64bd7c5a),segFN=segments_1,generation=1}
>> [junit4:junit4]   2> 437758 T536 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
>> [junit4:junit4]   2> 437763 T536 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
>> [junit4:junit4]   2> 437763 T536 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
>> [junit4:junit4]   2> 437765 T536 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
>> [junit4:junit4]   2> 437766 T536 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
>> [junit4:junit4]   2> 437767 T536 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
>> [junit4:junit4]   2> 437767 T536 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
>> [junit4:junit4]   2> 437861 T536 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
>> [junit4:junit4]   2> 437863 T536 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
>> [junit4:junit4]   2> 437863 T536 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
>> [junit4:junit4]   2> 437769 T537 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/awholynewcollection_0_shard1_replica2/data
>> [junit4:junit4]   2> 437870 T537 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/awholynewcollection_0_shard1_replica2/data/index/
>> [junit4:junit4]   2> 437871 T537 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard1_replica2] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/awholynewcollection_0_shard1_replica2/data/index' doesn't exist. Creating new index...
>> [junit4:junit4]   2> 437872 T523 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
>> [junit4:junit4]   2> 437781 T550 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
>> [junit4:junit4]   2> 437887 T525 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
>> [junit4:junit4]   2> 437773 T495 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
>> [junit4:junit4]   2> 437899 T537 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369134476911/awholynewcollection_0_shard1_replica2/data/index
>> [junit4:junit4]   2> 437934 T522 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
>> [junit4:junit4]   2>          commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@276ae22f lockFactory=org.apache.lucene.store.NativeFSLockFactory@126aa26c),segFN=segments_1,generation=1}
>> [junit4:junit4]   2> 437935 T522 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
>> [junit4:junit4]   2> 437939 T522 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
>> [junit4:junit4]   2> 437940 T522 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
>> [junit4:junit4]   2> 437941 T522 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
>> [junit4:junit4]   2> 437942 T522 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
>> [junit4:junit4]   2> 437942 T522 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
>> [junit4:junit4]   2> 437943 T522 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
>> [junit4:junit4]   2> 437944 T522 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
>> [junit4:junit4]   2> 438060 T522 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
>> [junit4:junit4]   2> 438061 T522 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
>> [junit4:junit4]   2> 438058 T537 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
>> [junit4:junit4]   2>          commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@14e2cf0a lockFactory=org.apache.lucene.store.NativeFSLockFactory@67
>>
>> [...truncated too long message...]
>>
>> /jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/misc/lucene-misc-4.4-SNAPSHOT.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/spatial/lucene-spatial-4.4-SNAPSHOT.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/suggest/lucene-suggest-4.4-SNAPSHOT.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/grouping/lucene-grouping-4.4-SNAPSHOT.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/queries/lucene-queries-4.4-SNAPSHOT.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/queryparser/lucene-queryparser-4.4-SNAPSHOT.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/cglib-nodep-2.2.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/commons-cli-1.2.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/commons-codec-1.7.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/commons-fileupload-1.2.1.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/commons-lang-2.6.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/easymock-3.0.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/guava-14.0.1.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/javax.servlet-api-3.0.1.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/objenesis-1.2.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/org.restlet-2.1.1.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/org.restlet.ext.servlet-2.1.1.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/core/lib/spatial4j-0.3.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/solrj/lib/commons-io-2.1.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/solrj/lib/httpclient-4.2.3.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/solrj/lib/httpcore-4.2.2.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/solrj/lib/httpmime-4.2.3.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/solrj/lib/jcl-over-slf4j-1.6.6.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/solrj/lib/jul-to-slf4j-1.6.6.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/solrj/lib/log4j-1.2.16.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/solrj/lib/noggit-0.5.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/solrj/lib/slf4j-api-1.6.6.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/solrj/lib/slf4j-log4j12-1.6.6.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/solrj/lib/wstx-asl-3.2.7.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/solrj/lib/zookeeper-3.4.5.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/jetty-continuation-8.1.10.v20130312.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/jetty-deploy-8.1.10.v20130312.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/jetty-http-8.1.10.v20130312.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/jetty-io-8.1.10.v20130312.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/jetty-jmx-8.1.10.v20130312.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/jetty-security-8.1.10.v20130312.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/jetty-server-8.1.10.v20130312.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/jetty-servlet-8.1.10.v20130312.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/jetty-util-8.1.10.v20130312.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/jetty-webapp-8.1.10.v20130312.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/jetty-xml-8.1.10.v20130312.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/lib/servlet-api-3.0.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/example-DIH/solr/db/lib/derby-10.9.1.0.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/example/example-DIH/solr/db/lib/hsqldb-1.8.0.10.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/build/core/classes/java:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/test-framework/lib/junit-4.10.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/test-framework/lib/randomizedtesting-runner-2.0.10.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-launcher.jar:/Users/jenkins/.ant/lib/ivy-2.3.0.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-antlr.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-bcel.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-bsf.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-log4j.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-oro.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-regexp.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-resolver.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-xalan2.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-commons-logging.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-commons-net.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jai.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-javamail.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jdepend.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jmf.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jsch.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-junit.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-junit4.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-netrexx.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-swing.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-testutil.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_21.jdk/Contents/Home/lib/tools.jar:/Users/jenkins/.ivy2/cache/com.carrotsearch.randomizedtesting/junit4-ant/jars/junit4-ant-2.0.10.jar -ea:org.apache.lucene... -ea:org.apache.solr... com.carrotsearch.ant.tasks.junit4.slave.SlaveMainSafe -flush -eventsfile /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/temp/junit4-J0-20130521_110105_355.events @/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/temp/junit4-J0-20130521_110105_355.suites
>> [junit4:junit4] ERROR: JVM J0 ended with an exception: Forked process returned with error code: 134. Very likely a JVM crash.  Process output piped in logs above.
>> [junit4:junit4]       at com.carrotsearch.ant.tasks.junit4.JUnit4.executeSlave(JUnit4.java:1254)
>> [junit4:junit4]       at com.carrotsearch.ant.tasks.junit4.JUnit4.access$000(JUnit4.java:67)
>> [junit4:junit4]       at com.carrotsearch.ant.tasks.junit4.JUnit4$2.call(JUnit4.java:822)
>> [junit4:junit4]       at com.carrotsearch.ant.tasks.junit4.JUnit4$2.call(JUnit4.java:819)
>> [junit4:junit4]       at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
>> [junit4:junit4]       at java.util.concurrent.FutureTask.run(FutureTask.java:166)
>> [junit4:junit4]       at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
>> [junit4:junit4]       at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
>> [junit4:junit4]       at java.lang.Thread.run(Thread.java:722)
>>
>> BUILD FAILED
>> /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/build.xml:386: The following error occurred while executing this line:
>> /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/build.xml:366: The following error occurred while executing this line:
>> /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/build.xml:39: The following error occurred while executing this line:
>> /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/build.xml:181: The following error occurred while executing this line:
>> /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/solr/common-build.xml:437: The following error occurred while executing this line:
>> /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:1243: The following error occurred while executing this line:
>> /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:887: At least one slave process threw an exception, first: Forked process returned with error code: 134. Very likely a JVM crash.  Process output piped in logs above.
>>
>> Total time: 95 minutes 3 seconds
>> Build step 'Invoke Ant' marked build as failure
>> Description set: Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseParallelGC
>> Archiving artifacts
>> Recording test results
>> Email was triggered for: Failure
>> Sending email for trigger: Failure
>>
>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
>> For additional commands, e-mail: dev-help@lucene.apache.org
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
> For additional commands, e-mail: dev-help@lucene.apache.org
>

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@lucene.apache.org
For additional commands, e-mail: dev-help@lucene.apache.org


Mime
View raw message