lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-trunk-MacOSX (64bit/jdk1.7.0) - Build # 567 - Still Failing!
Date Sun, 16 Jun 2013 10:12:04 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-MacOSX/567/
Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC

2 tests failed.
REGRESSION:  org.apache.solr.cloud.RecoveryZkTest.testDistribSearch

Error Message:
expected:<154> but was:<26>

Stack Trace:
java.lang.AssertionError: expected:<154> but was:<26>
	at __randomizedtesting.SeedInfo.seed([CA7940D8D7D1E2D2:4B9FCEC0A08E82EE]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.failNotEquals(Assert.java:647)
	at org.junit.Assert.assertEquals(Assert.java:128)
	at org.junit.Assert.assertEquals(Assert.java:472)
	at org.junit.Assert.assertEquals(Assert.java:456)
	at org.apache.solr.cloud.RecoveryZkTest.doTest(RecoveryZkTest.java:108)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:815)
	at sun.reflect.GeneratedMethodAccessor39.invoke(Unknown Source)
	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)


FAILED:  org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testDistribSearch

Error Message:
collection already exists: awholynewcollection_1

Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: collection already exists: awholynewcollection_1
	at __randomizedtesting.SeedInfo.seed([CA7940D8D7D1E2D2:4B9FCEC0A08E82EE]:0)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:424)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
	at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:264)
	at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:306)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1400)
	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:438)
	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 9574 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4:junit4]   2> 2424217 T4562 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4]   2> 2424233 T4562 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4]   2> Creating dataDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1371375666698
[junit4:junit4]   2> 2424236 T4562 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 2424237 T4563 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4]   2> 2424339 T4562 oasc.ZkTestServer.run start zk server on port:50550
[junit4:junit4]   2> 2424343 T4562 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 2424349 T4569 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c98ce9 name:ZooKeeperConnection Watcher:127.0.0.1:50550 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 2424350 T4562 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 2424350 T4562 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 2424368 T4562 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 2424375 T4571 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@33ccb082 name:ZooKeeperConnection Watcher:127.0.0.1:50550/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 2424376 T4562 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 2424376 T4562 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 2424385 T4562 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 2424394 T4562 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 2424402 T4562 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 2424413 T4562 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 2424414 T4562 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 2424429 T4562 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4]   2> 2424430 T4562 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 2424441 T4562 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4]   2> 2424442 T4562 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 2424453 T4562 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4]   2> 2424455 T4562 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 2424471 T4562 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4]   2> 2424474 T4562 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 2424485 T4562 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 2424487 T4562 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 2424499 T4562 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 2424501 T4562 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 2424514 T4562 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 2424517 T4562 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 2424534 T4562 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4]   2> 2424536 T4562 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 2425325 T4562 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4]   2> 2425340 T4562 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50553
[junit4:junit4]   2> 2425341 T4562 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 2425342 T4562 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 2425343 T4562 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1371375667015
[junit4:junit4]   2> 2425344 T4562 oasc.CoreContainer$Initializer.initialize looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1371375667015/solr.xml
[junit4:junit4]   2> 2425345 T4562 oasc.CoreContainer.<init> New CoreContainer 749834578
[junit4:junit4]   2> 2425347 T4562 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1371375667015/'
[junit4:junit4]   2> 2425348 T4562 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1371375667015/'
[junit4:junit4]   2> 2425669 T4562 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1371375667015
[junit4:junit4]   2> 2425673 T4562 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1371375667015/collection1
[junit4:junit4]   2> 2425676 T4562 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1371375667015/collection1/conf
[junit4:junit4]   2> 2425938 T4562 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1371375667015/collection1/conf/xslt
[junit4:junit4]   2> 2425944 T4562 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1371375667015/collection1/lib
[junit4:junit4]   2> 2425946 T4562 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1371375667015/collection1/lib/classes
[junit4:junit4]   2> 2425949 T4562 oasc.SolrCoreDiscoverer.addCore Discovered properties file /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1371375667015/conf/core.properties, adding to cores
[junit4:junit4]   2> 2425978 T4562 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 2425979 T4562 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 2425980 T4562 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 2425980 T4562 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 2425981 T4562 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 2425982 T4562 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 2425982 T4562 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 2425983 T4562 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 2425984 T4562 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 2425985 T4562 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 2426028 T4562 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4]   2> 2426030 T4562 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50550/solr
[junit4:junit4]   2> 2426031 T4562 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 2426046 T4582 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6a8483d name:ZooKeeperConnection Watcher:127.0.0.1:50550 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 2426049 T4562 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 2426053 T4562 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 2426071 T4562 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 2426109 T4562 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 2426139 T4584 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@61cf83a9 name:ZooKeeperConnection Watcher:127.0.0.1:50550/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 2426155 T4562 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 2426182 T4562 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4]   2> 2426216 T4562 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4]   2> 2426248 T4562 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 2426256 T4562 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50553_
[junit4:junit4]   2> 2426267 T4562 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50553_
[junit4:junit4]   2> 2426285 T4562 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 2426304 T4562 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 2426316 T4562 oasc.Overseer.start Overseer (id=89874475693375491-127.0.0.1:50553_-n_0000000000) starting
[junit4:junit4]   2> 2426333 T4562 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4]   2> 2426353 T4586 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 2426357 T4585 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 2426363 T4562 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 2426379 T4562 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4]   2> 2426386 T4562 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 2426401 T4562 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4]   2> 2426402 T4562 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 2426403 T4562 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 2426426 T4562 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 2426432 T4562 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 2426444 T4589 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7e872f68 name:ZooKeeperConnection Watcher:127.0.0.1:50550/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 2426444 T4562 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 2426449 T4562 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 2426481 T4562 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   2> 2427067 T4562 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4]   2> 2427077 T4562 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50557
[junit4:junit4]   2> 2427079 T4562 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 2427080 T4562 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 2427080 T4562 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945
[junit4:junit4]   2> 2427081 T4562 oasc.CoreContainer$Initializer.initialize looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945/solr.xml
[junit4:junit4]   2> 2427081 T4562 oasc.CoreContainer.<init> New CoreContainer 987784
[junit4:junit4]   2> 2427083 T4562 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945/'
[junit4:junit4]   2> 2427084 T4562 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945/'
[junit4:junit4]   2> 2427349 T4562 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945
[junit4:junit4]   2> 2427351 T4562 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945/collection1
[junit4:junit4]   2> 2427353 T4562 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945/collection1/conf
[junit4:junit4]   2> 2427531 T4562 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945/collection1/conf/xslt
[junit4:junit4]   2> 2427539 T4562 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945/collection1/lib
[junit4:junit4]   2> 2427542 T4562 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945/collection1/lib/classes
[junit4:junit4]   2> 2427548 T4562 oasc.SolrCoreDiscoverer.addCore Discovered properties file /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945/conf/core.properties, adding to cores
[junit4:junit4]   2> 2427569 T4562 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 2427570 T4562 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 2427571 T4562 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 2427572 T4562 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 2427572 T4562 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 2427573 T4562 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 2427574 T4562 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 2427574 T4562 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 2427575 T4562 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 2427576 T4562 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 2427603 T4562 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4]   2> 2427605 T4562 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50550/solr
[junit4:junit4]   2> 2427606 T4562 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 2427610 T4562 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 2427622 T4600 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@394ca9b1 name:ZooKeeperConnection Watcher:127.0.0.1:50550 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 2427624 T4562 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 2427632 T4562 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 2427662 T4602 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@58c56553 name:ZooKeeperConnection Watcher:127.0.0.1:50550/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 2427663 T4562 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 2427664 T4562 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 2427684 T4562 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 2428697 T4562 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50557_
[junit4:junit4]   2> 2428700 T4562 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50557_
[junit4:junit4]   2> 2428708 T4584 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 2428746 T4589 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 2428746 T4602 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 2428758 T4562 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4]   2> 2428759 T4562 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 2428760 T4562 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 2429419 T4562 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4]   2> 2429428 T4562 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50560
[junit4:junit4]   2> 2429429 T4562 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 2429430 T4562 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 2429431 T4562 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1371375671246
[junit4:junit4]   2> 2429431 T4562 oasc.CoreContainer$Initializer.initialize looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1371375671246/solr.xml
[junit4:junit4]   2> 2429432 T4562 oasc.CoreContainer.<init> New CoreContainer 981229902
[junit4:junit4]   2> 2429433 T4562 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1371375671246/'
[junit4:junit4]   2> 2429433 T4562 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1371375671246/'
[junit4:junit4]   2> 2429660 T4562 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1371375671246
[junit4:junit4]   2> 2429663 T4562 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1371375671246/collection1
[junit4:junit4]   2> 2429664 T4562 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1371375671246/collection1/conf
[junit4:junit4]   2> 2429846 T4562 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1371375671246/collection1/conf/xslt
[junit4:junit4]   2> 2429851 T4562 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1371375671246/collection1/lib
[junit4:junit4]   2> 2429853 T4562 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1371375671246/collection1/lib/classes
[junit4:junit4]   2> 2429858 T4562 oasc.SolrCoreDiscoverer.addCore Discovered properties file /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1371375671246/conf/core.properties, adding to cores
[junit4:junit4]   2> 2429873 T4562 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 2429874 T4562 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 2429875 T4562 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 2429876 T4562 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 2429877 T4562 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 2429877 T4562 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 2429878 T4562 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 2429879 T4562 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 2429879 T4562 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 2429880 T4562 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 2429913 T4562 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4]   2> 2429914 T4562 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50550/solr
[junit4:junit4]   2> 2429915 T4562 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 2429917 T4562 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 2429922 T4614 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5f6be886 name:ZooKeeperConnection Watcher:127.0.0.1:50550 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 2429924 T4562 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 2429929 T4562 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 2429938 T4564 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13f4c5c06140007, likely client has closed socket
[junit4:junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4]   2> 	at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   2> 
[junit4:junit4]   2> 2429953 T4562 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 2429960 T4616 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9555412 name:ZooKeeperConnection Watcher:127.0.0.1:50550/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 2429961 T4562 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 2429981 T4562 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 2430998 T4562 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50560_
[junit4:junit4]   2> 2431001 T4562 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50560_
[junit4:junit4]   2> 2431008 T4584 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 2431013 T4602 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 2431014 T4589 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 2431025 T4616 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 2431026 T4562 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4]   2> 2431026 T4562 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 2431027 T4562 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 2431606 T4562 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4]   2> 2431617 T4562 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50563
[junit4:junit4]   2> 2431618 T4562 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 2431619 T4562 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 2431620 T4562 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371375673518
[junit4:junit4]   2> 2431621 T4562 oasc.CoreContainer$Initializer.initialize looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371375673518/solr.xml
[junit4:junit4]   2> 2431621 T4562 oasc.CoreContainer.<init> New CoreContainer 1185895665
[junit4:junit4]   2> 2431622 T4562 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371375673518/'
[junit4:junit4]   2> 2431623 T4562 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371375673518/'
[junit4:junit4]   2> 2431829 T4562 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371375673518
[junit4:junit4]   2> 2431831 T4562 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371375673518/collection1
[junit4:junit4]   2> 2431834 T4562 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371375673518/collection1/conf
[junit4:junit4]   2> 2432043 T4562 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371375673518/collection1/conf/xslt
[junit4:junit4]   2> 2432050 T4562 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371375673518/collection1/lib
[junit4:junit4]   2> 2432052 T4562 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371375673518/collection1/lib/classes
[junit4:junit4]   2> 2432055 T4562 oasc.SolrCoreDiscoverer.addCore Discovered properties file /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371375673518/conf/core.properties, adding to cores
[junit4:junit4]   2> 2432071 T4562 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 2432072 T4562 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 2432073 T4562 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 2432073 T4562 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 2432074 T4562 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 2432075 T4562 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 2432075 T4562 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 2432076 T4562 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 2432076 T4562 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 2432077 T4562 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 2432113 T4562 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4]   2> 2432114 T4562 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50550/solr
[junit4:junit4]   2> 2432115 T4562 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 2432117 T4562 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 2432123 T4628 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d35441e name:ZooKeeperConnection Watcher:127.0.0.1:50550 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 2432126 T4562 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 2432135 T4562 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 2432173 T4562 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 2432179 T4630 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@200aeee9 name:ZooKeeperConnection Watcher:127.0.0.1:50550/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 2432180 T4562 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 2432198 T4562 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 2433222 T4562 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50563_
[junit4:junit4]   2> 2433226 T4562 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50563_
[junit4:junit4]   2> 2433237 T4602 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 2433240 T4616 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 2433243 T4584 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 2433252 T4589 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 2433254 T4630 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 2433269 T4562 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4]   2> 2433270 T4562 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 2433270 T4562 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 2433876 T4562 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4]   2> 2433884 T4562 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50566
[junit4:junit4]   2> 2433892 T4562 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 2433893 T4562 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 2433894 T4562 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1371375675754
[junit4:junit4]   2> 2433896 T4562 oasc.CoreContainer$Initializer.initialize looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1371375675754/solr.xml
[junit4:junit4]   2> 2433898 T4562 oasc.CoreContainer.<init> New CoreContainer 1007950415
[junit4:junit4]   2> 2433900 T4562 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1371375675754/'
[junit4:junit4]   2> 2433901 T4562 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1371375675754/'
[junit4:junit4]   2> 2434169 T4562 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1371375675754
[junit4:junit4]   2> 2434178 T4562 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1371375675754/collection1
[junit4:junit4]   2> 2434180 T4562 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1371375675754/collection1/conf
[junit4:junit4]   2> 2434370 T4562 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1371375675754/collection1/conf/xslt
[junit4:junit4]   2> 2434378 T4562 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1371375675754/collection1/lib
[junit4:junit4]   2> 2434384 T4562 oasc.SolrCoreDiscoverer.walkFromHere Looking for cores in /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1371375675754/collection1/lib/classes
[junit4:junit4]   2> 2434388 T4562 oasc.SolrCoreDiscoverer.addCore Discovered properties file /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1371375675754/conf/core.properties, adding to cores
[junit4:junit4]   2> 2434407 T4562 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4]   2> 2434408 T4562 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 2434409 T4562 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4]   2> 2434409 T4562 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 2434410 T4562 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 2434411 T4562 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 2434411 T4562 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 2434412 T4562 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 2434413 T4562 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 2434414 T4562 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4]   2> 2434442 T4562 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4]   2> 2434444 T4562 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50550/solr
[junit4:junit4]   2> 2434454 T4562 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 2434457 T4562 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 2434462 T4642 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@58edf9b name:ZooKeeperConnection Watcher:127.0.0.1:50550 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 2434464 T4562 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 2434471 T4562 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 2434503 T4562 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 2434505 T4644 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ccfa2ca name:ZooKeeperConnection Watcher:127.0.0.1:50550/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 2434506 T4562 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 2434521 T4562 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 2435533 T4562 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50566_
[junit4:junit4]   2> 2435537 T4562 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50566_
[junit4:junit4]   2> 2435551 T4630 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 2435552 T4602 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 2435554 T4644 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 2435573 T4616 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 2435575 T4562 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4]   2> 2435576 T4562 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 2435577 T4562 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 2435577 T4589 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 2435578 T4584 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 2435634 T4562 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 2435665 T4597 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=2&name=nodes_used_collection&replicationFactor=2&action=CREATE&wt=javabin&version=2
[junit4:junit4]   2> 2435669 T4584 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4]   2> 2435673 T4584 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4]   2> 2435676 T4586 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> 2435677 T4586 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:50566_
[junit4:junit4]   2> 2435677 T4586 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:50560_
[junit4:junit4]   2> 2435678 T4586 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:50557_
[junit4:junit4]   2> 2435678 T4586 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:50563_
[junit4:junit4]   2> 2435710 T4625 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica2 state=down
[junit4:junit4]   2> 2435713 T4598 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica1 state=down
[junit4:junit4]   2> 2435716 T4609 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica2 state=down
[junit4:junit4]   2> 2435717 T4639 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=down
[junit4:junit4]   2> 2437048 T4585 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2437050 T4585 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:50563_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:50563"}
[junit4:junit4]   2> 2437050 T4585 oasc.Overseer$ClusterStateUpdater.createCollection Create collection nodes_used_collection with numShards 2
[junit4:junit4]   2> 2437063 T4585 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:50557_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:50557"}
[junit4:junit4]   2> 2437074 T4585 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:50566_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:50566"}
[junit4:junit4]   2> 2437085 T4585 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:50560_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:50560"}
[junit4:junit4]   2> 2437099 T4630 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> 2437100 T4616 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> 2437101 T4644 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> 2437108 T4589 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> 2437109 T4584 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> 2437111 T4602 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> 2437722 T4625 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard2_replica2' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371375673518/nodes_used_collection_shard2_replica2
[junit4:junit4]   2> 2437723 T4625 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4]   2> 2437724 T4609 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard1_replica2' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1371375671246/nodes_used_collection_shard1_replica2
[junit4:junit4]   2> 2437725 T4609 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4]   2> 2437725 T4639 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard1_replica1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1371375675754/nodes_used_collection_shard1_replica1
[junit4:junit4]   2> 2437726 T4639 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4]   2> 2437728 T4598 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard2_replica1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945/nodes_used_collection_shard2_replica1
[junit4:junit4]   2> 2437728 T4598 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4]   2> 2437729 T4639 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4]   2> 2437731 T4639 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4]   2> 2437738 T4609 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4]   2> 2437738 T4609 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4]   2> 2437740 T4598 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4]   2> 2437741 T4598 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4]   2> 2437742 T4625 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4]   2> 2437743 T4625 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4]   2> 2437744 T4609 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4]   2> 2437744 T4609 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4]   2> 2437748 T4598 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4]   2> 2437749 T4598 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4]   2> 2437751 T4625 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4]   2> 2437752 T4625 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4]   2> 2437752 T4639 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4]   2> 2437758 T4639 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4]   2> 2437760 T4609 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4]   2> 2437759 T4598 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4]   2> 2437768 T4598 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945/nodes_used_collection_shard2_replica1/'
[junit4:junit4]   2> 2437778 T4625 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4]   2> 2437784 T4625 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371375673518/nodes_used_collection_shard2_replica2/'
[junit4:junit4]   2> 2437787 T4609 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1371375671246/nodes_used_collection_shard1_replica2/'
[junit4:junit4]   2> 2437793 T4639 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4]   2> 2437804 T4639 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1371375675754/nodes_used_collection_shard1_replica1/'
[junit4:junit4]   2> 2438134 T4625 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 2438192 T4639 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 2438196 T4609 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 2438219 T4598 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 2438590 T4639 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 2438595 T4639 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4]   2> 2438603 T4639 oass.IndexSchema.readSchema [nodes_used_collection_shard1_replica1] Schema name=test
[junit4:junit4]   2> 2438616 T4609 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 2438624 T4625 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 2438638 T4609 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4]   2> 2438643 T4625 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4]   2> 2438650 T4609 oass.IndexSchema.readSchema [nodes_used_collection_shard1_replica2] Schema name=test
[junit4:junit4]   2> 2438654 T4625 oass.IndexSchema.readSchema [nodes_used_collection_shard2_replica2] Schema name=test
[junit4:junit4]   2> 2438677 T4598 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 2438739 T4598 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4]   2> 2438756 T4598 oass.IndexSchema.readSchema [nodes_used_collection_shard2_replica1] Schema name=test
[junit4:junit4]   2> 2442514 T4639 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 2442541 T4625 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 2442578 T4639 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 2442580 T4625 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 2442586 T4625 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 2442591 T4609 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 2442592 T4639 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 2442600 T4598 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 2442646 T4609 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 2442682 T4625 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 2442704 T4609 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 2442712 T4625 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 2442719 T4598 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 2442760 T4598 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 2442776 T4639 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 2442785 T4639 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 2442808 T4639 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 2442824 T4625 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 2442830 T4625 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 2442836 T4625 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 2442837 T4625 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 2442864 T4639 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 2442869 T4639 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 2442870 T4639 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 2442870 T4625 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 2442874 T4625 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 2442875 T4625 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 2442876 T4625 oasc.SolrCore.<init> [nodes_used_collection_shard2_replica2] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371375673518/nodes_used_collection_shard2_replica2/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371375673518/nodes_used_collection_shard2_replica2/data/
[junit4:junit4]   2> 2442876 T4625 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2060182
[junit4:junit4]   2> 2442877 T4625 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 2442879 T4625 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371375673518/nodes_used_collection_shard2_replica2/data
[junit4:junit4]   2> 2442879 T4625 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371375673518/nodes_used_collection_shard2_replica2/data/index/
[junit4:junit4]   2> 2442882 T4625 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard2_replica2] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371375673518/nodes_used_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 2442883 T4639 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 2442883 T4639 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 2442884 T4639 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 2442886 T4639 oasc.SolrCore.<init> [nodes_used_collection_shard1_replica1] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1371375675754/nodes_used_collection_shard1_replica1/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1371375675754/nodes_used_collection_shard1_replica1/data/
[junit4:junit4]   2> 2442886 T4639 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2060182
[junit4:junit4]   2> 2442887 T4639 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 2442887 T4609 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 2442887 T4625 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371375673518/nodes_used_collection_shard2_replica2/data/index
[junit4:junit4]   2> 2442892 T4639 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1371375675754/nodes_used_collection_shard1_replica1/data
[junit4:junit4]   2> 2442894 T4639 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1371375675754/nodes_used_collection_shard1_replica1/data/index/
[junit4:junit4]   2> 2442895 T4639 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard1_replica1] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1371375675754/nodes_used_collection_shard1_replica1/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 2442900 T4609 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 2442903 T4598 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 2442901 T4639 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1371375675754/nodes_used_collection_shard1_replica1/data/index
[junit4:junit4]   2> 2442903 T4625 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1f3910c2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@27a1dd15),segFN=segments_1,generation=1}
[junit4:junit4]   2> 2442907 T4625 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 2442924 T4625 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 2442929 T4625 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 2442930 T4625 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 2442932 T4625 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 2442933 T4625 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 2442939 T4625 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 2442940 T4625 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 2442942 T4625 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 2442943 T4625 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 2442947 T4598 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 2442937 T4639 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@a7a7ea2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7ca31792),segFN=segments_1,generation=1}
[junit4:junit4]   2> 2442949 T4639 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 2442940 T4609 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 2442957 T4639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 2442958 T4639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 2442959 T4639 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 2442961 T4639 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 2442962 T4639 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 2442965 T4639 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 2442966 T4639 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 2442967 T4639 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 2442968 T4639 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 2442979 T4625 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 2442987 T4609 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 2442993 T4609 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 2442993 T4609 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 2442995 T4639 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 2443006 T4609 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 2443012 T4609 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 2443013 T4609 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 2443013 T4609 oasc.SolrCore.<init> [nodes_used_collection_shard1_replica2] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1371375671246/nodes_used_collection_shard1_replica2/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1371375671246/nodes_used_collection_shard1_replica2/data/
[junit4:junit4]   2> 2443014 T4609 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2060182
[junit4:junit4]   2> 2443015 T4609 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 2443011 T4625 oass.SolrIndexSearcher.<init> Opening Searcher@da64bb1 main
[junit4:junit4]   2> 2443017 T4625 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371375673518/nodes_used_collection_shard2_replica2/data/tlog
[junit4:junit4]   2> 2443019 T4625 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 2443019 T4625 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 2443010 T4639 oass.SolrIndexSearcher.<init> Opening Searcher@3bdbc113 main
[junit4:junit4]   2> 2443026 T4639 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1371375675754/nodes_used_collection_shard1_replica1/data/tlog
[junit4:junit4]   2> 2443032 T4651 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica2] Registered new searcher Searcher@da64bb1 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 2443009 T4598 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 2443032 T4639 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 2443035 T4639 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 2443023 T4609 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1371375671246/nodes_used_collection_shard1_replica2/data
[junit4:junit4]   2> 2443037 T4609 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1371375671246/nodes_used_collection_shard1_replica2/data/index/
[junit4:junit4]   2> 2443037 T4609 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard1_replica2] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1371375671246/nodes_used_collection_shard1_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 2443039 T4609 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1371375671246/nodes_used_collection_shard1_replica2/data/index
[junit4:junit4]   2> 2443041 T4650 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica1] Registered new searcher Searcher@3bdbc113 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 2443047 T4598 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 2443048 T4598 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 2443049 T4598 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 2443050 T4639 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard1_replica1
[junit4:junit4]   2> 2443051 T4639 oasc.ZkController.register Register replica - core:nodes_used_collection_shard1_replica1 address:http://127.0.0.1:50566 collection:nodes_used_collection shard:shard1
[junit4:junit4]   2> 2443048 T4625 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard2_replica2
[junit4:junit4]   2> 2443053 T4625 oasc.ZkController.register Register replica - core:nodes_used_collection_shard2_replica2 address:http://127.0.0.1:50563 collection:nodes_used_collection shard:shard2
[junit4:junit4]   2> 2443051 T4609 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2b448545 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7ba3cdd4),segFN=segments_1,generation=1}
[junit4:junit4]   2> 2443054 T4609 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 2443056 T4625 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard2/election
[junit4:junit4]   2> 2443056 T4598 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 2443058 T4598 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 2443058 T4598 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 2443059 T4598 oasc.SolrCore.<init> [nodes_used_collection_shard2_replica1] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945/nodes_used_collection_shard2_replica1/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945/nodes_used_collection_shard2_replica1/data/
[junit4:junit4]   2> 2443061 T4598 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2060182
[junit4:junit4]   2> 2443062 T4598 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 2443059 T4639 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard1/election
[junit4:junit4]   2> 2443066 T4609 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 2443067 T4609 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 2443068 T4609 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 2443069 T4609 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 2443070 T4609 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 2443071 T4609 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 2443072 T4609 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 2443073 T4609 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 2443073 T4598 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945/nodes_used_collection_shard2_replica1/data
[junit4:junit4]   2> 2443077 T4609 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 2443087 T4598 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945/nodes_used_collection_shard2_replica1/data/index/
[junit4:junit4]   2> 2443087 T4598 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard2_replica1] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945/nodes_used_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 2443099 T4598 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945/nodes_used_collection_shard2_replica1/data/index
[junit4:junit4]   2> 2443101 T4609 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 2443126 T4609 oass.SolrIndexSearcher.<init> Opening Searcher@483eca37 main
[junit4:junit4]   2> 2443127 T4609 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1371375671246/nodes_used_collection_shard1_replica2/data/tlog
[junit4:junit4]   2> 2443128 T4598 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6ac7286a lockFactory=org.apache.lucene.store.NativeFSLockFactory@466d1116),segFN=segments_1,generation=1}
[junit4:junit4]   2> 2443129 T4598 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 2443129 T4609 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 2443131 T4609 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 2443145 T4652 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica2] Registered new searcher Searcher@483eca37 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 2443153 T4598 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 2443154 T4598 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 2443155 T4598 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 2443156 T4598 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 2443158 T4598 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 2443158 T4598 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 2443159 T4598 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 2443160 T4598 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 2443163 T4598 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 2443198 T4609 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard1_replica2
[junit4:junit4]   2> 2443199 T4609 oasc.ZkController.register Register replica - core:nodes_used_collection_shard1_replica2 address:http://127.0.0.1:50560 collection:nodes_used_collection shard:shard1
[junit4:junit4]   2> 2443209 T4598 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 2443241 T4609 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 2443247 T4598 oass.SolrIndexSearcher.<init> Opening Searcher@7857c57a main
[junit4:junit4]   2> 2443248 T4598 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945/nodes_used_collection_shard2_replica1/data/tlog
[junit4:junit4]   2> 2443253 T4598 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 2443254 T4598 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 2443254 T4625 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 2443260 T4653 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica1] Registered new searcher Searcher@7857c57a main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 2443266 T4598 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard2_replica1
[junit4:junit4]   2> 2443269 T4598 oasc.ZkController.register Register replica - core:nodes_used_collection_shard2_replica1 address:http://127.0.0.1:50557 collection:nodes_used_collection shard:shard2
[junit4:junit4]   2> 2443311 T4609 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 2443312 T4625 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=179998
[junit4:junit4]   2> 2443312 T4609 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 2443315 T4609 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50560/nodes_used_collection_shard1_replica2/
[junit4:junit4]   2> 2443316 T4609 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica2 url=http://127.0.0.1:50560 START replicas=[http://127.0.0.1:50566/nodes_used_collection_shard1_replica1/] nUpdates=100
[junit4:junit4]   2> 2443319 T4609 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica2 url=http://127.0.0.1:50560 DONE.  We have no versions.  sync failed.
[junit4:junit4]   2> 2443322 T4609 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4]   2> 2443323 T4609 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> 2443323 T4609 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50560/nodes_used_collection_shard1_replica2/
[junit4:junit4]   2> 2443324 T4609 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leaders/shard1
[junit4:junit4]   2> ASYNC  NEW_CORE C2679 name=nodes_used_collection_shard1_replica1 org.apache.solr.core.SolrCore@20e726c3 url=http://127.0.0.1:50566/nodes_used_collection_shard1_replica1 node=127.0.0.1:50566_ C2679_STATE=coll:nodes_used_collection core:nodes_used_collection_shard1_replica1 props:{shard=shard1, state=down, core=nodes_used_collection_shard1_replica1, collection=nodes_used_collection, node_name=127.0.0.1:50566_, base_url=http://127.0.0.1:50566}
[junit4:junit4]   2> 2443339 T4636 C2679 P50566 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=6 
[junit4:junit4]   2> 2443816 T4625 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 2443817 T4625 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 2443817 T4625 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50563/nodes_used_collection_shard2_replica2/
[junit4:junit4]   2> 2443818 T4625 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica2 url=http://127.0.0.1:50563 START replicas=[http://127.0.0.1:50557/nodes_used_collection_shard2_replica1/] nUpdates=100
[junit4:junit4]   2> 2443819 T4625 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica2 url=http://127.0.0.1:50563 DONE.  We have no versions.  sync failed.
[junit4:junit4]   2> 2443821 T4625 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4]   2> 2443821 T4625 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> 2443822 T4625 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50563/nodes_used_collection_shard2_replica2/
[junit4:junit4]   2> 2443822 T4625 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leaders/shard2
[junit4:junit4]   2> ASYNC  NEW_CORE C2680 name=nodes_used_collection_shard2_replica1 org.apache.solr.core.SolrCore@3e1ecf6d url=http://127.0.0.1:50557/nodes_used_collection_shard2_replica1 node=127.0.0.1:50557_ C2680_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:50557_, base_url=http://127.0.0.1:50557}
[junit4:junit4]   2> 2443853 T4596 C2680 P50557 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=1 
[junit4:junit4]   2> 2444747 T4585 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2444794 T4616 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> 2444795 T4602 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> 2444795 T4644 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> 2444800 T4630 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> 2444804 T4584 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> 2444804 T4589 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> 2444819 T4639 oasc.ZkController.register We are http://127.0.0.1:50566/nodes_used_collection_shard1_replica1/ and leader is http://127.0.0.1:50560/nodes_used_collection_shard1_replica2/
[junit4:junit4]   2> 2444820 T4639 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard1_replica1 baseURL=http://127.0.0.1:50566
[junit4:junit4]   2> 2444821 T4639 oasc.ZkController.checkRecovery Core needs to recover:nodes_used_collection_shard1_replica1
[junit4:junit4]   2> 2444821 T4639 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> 2444823 T4656 C2679 P50566 oasc.RecoveryStrategy.run Starting recovery process.  core=nodes_used_collection_shard1_replica1 recoveringAfterStartup=true
[junit4:junit4]   2> 2444824 T4656 C2679 P50566 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 2444824 T4639 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2444826 T4656 C2679 P50566 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=recovering
[junit4:junit4]   2> 2444834 T4639 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=9117 
[junit4:junit4]   2> 2444840 T4598 oasc.ZkController.register We are http://127.0.0.1:50557/nodes_used_collection_shard2_replica1/ and leader is http://127.0.0.1:50563/nodes_used_collection_shard2_replica2/
[junit4:junit4]   2> 2444840 T4598 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard2_replica1 baseURL=http://127.0.0.1:50557
[junit4:junit4]   2> 2444841 T4598 oasc.ZkController.checkRecovery Core needs to recover:nodes_used_collection_shard2_replica1
[junit4:junit4]   2> 2444841 T4598 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> 2444843 T4657 C2680 P50557 oasc.RecoveryStrategy.run Starting recovery process.  core=nodes_used_collection_shard2_replica1 recoveringAfterStartup=true
[junit4:junit4]   2> 2444843 T4657 C2680 P50557 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 2444844 T4656 C2679 P50566 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 2444862 T4625 oasc.ZkController.register We are http://127.0.0.1:50563/nodes_used_collection_shard2_replica2/ and leader is http://127.0.0.1:50563/nodes_used_collection_shard2_replica2/
[junit4:junit4]   2> 2444863 T4625 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard2_replica2 baseURL=http://127.0.0.1:50563
[junit4:junit4]   2> 2444864 T4625 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 2444864 T4625 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica2 state=active
[junit4:junit4]   2> 2444865 T4609 oasc.ZkController.register We are http://127.0.0.1:50560/nodes_used_collection_shard1_replica2/ and leader is http://127.0.0.1:50560/nodes_used_collection_shard1_replica2/
[junit4:junit4]   2> 2444866 T4609 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard1_replica2 baseURL=http://127.0.0.1:50560
[junit4:junit4]   2> 2444875 T4609 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 2444876 T4609 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica2 state=active
[junit4:junit4]   2> 2444866 T4657 C2680 P50557 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica1 state=recovering
[junit4:junit4]   2> 2444879 T4598 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2444885 T4598 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=9172 
[junit4:junit4]   2> 2444885 T4657 C2680 P50557 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 2444886 T4625 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2444903 T4612 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:50566__nodes_used_collection_shard1_replica1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4]   2> 2444910 T4609 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2444915 T4625 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=9205 
[junit4:junit4]   2> 2444916 T4609 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=9200 
[junit4:junit4]   2> 2444927 T4586 oasc.OverseerCollectionProcessor.createCollection Finished create command on all shards for collection: nodes_used_collection
[junit4:junit4]   2> 2444939 T4602 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work/qnr-0000000000 state: SyncConnected type NodeDataChanged
[junit4:junit4]   2> 2444947 T4597 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=9282 
[junit4:junit4]   2> 2444949 T4586 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Message id:/overseer/collection-queue-work/qn-0000000000 complete, response:{success={null={responseHeader={status=0,QTime=9117},core=nodes_used_collection_shard1_replica1},null={responseHeader={status=0,QTime=9172},core=nodes_used_collection_shard2_replica1},null={responseHeader={status=0,QTime=9205},core=nodes_used_collection_shard2_replica2},null={responseHeader={status=0,QTime=9200},core=nodes_used_collection_shard1_replica2}}}
[junit4:junit4]   2> 2444949 T4562 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 2444954 T4562 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 2444960 T4659 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15fc6c5f name:ZooKeeperConnection Watcher:127.0.0.1:50550/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 2444962 T4562 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 2444965 T4626 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:50557__nodes_used_collection_shard2_replica1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4]   2> 2444970 T4562 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 2444981 T4562 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 2444989 T4562 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 2444994 T4661 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@47e4dd92 name:ZooKeeperConnection Watcher:127.0.0.1:50550/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 2444994 T4562 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 2445003 T4562 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 2445038 T4637 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=1&maxShardsPerNode=1&name=awholynewcollection_0&replicationFactor=4&action=CREATE&wt=javabin&version=2
[junit4:junit4]   2> 2445041 T4584 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4]   2> 2445047 T4584 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4]   2> 2445049 T4586 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":"1",
[junit4:junit4]   2> 	  "maxShardsPerNode":"1",
[junit4:junit4]   2> 	  "createNodeSet":null,
[junit4:junit4]   2> 	  "name":"awholynewcollection_0",
[junit4:junit4]   2> 	  "replicationFactor":"4"}
[junit4:junit4]   2> 2445049 T4586 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica1 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:50560_
[junit4:junit4]   2> 2445050 T4586 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica2 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:50553_
[junit4:junit4]   2> 2445050 T4586 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica3 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:50563_
[junit4:junit4]   2> 2445051 T4586 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica4 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:50557_
[junit4:junit4]   2> 2445057 T4607 oasc.ZkController.publish publishing core=awholynewcollection_0_shard1_replica1 state=down
[junit4:junit4]   2> 2445060 T4579 oasc.ZkController.publish publishing core=awholynewcollection_0_shard1_replica2 state=down
[junit4:junit4]   2> 2445062 T4622 oasc.ZkController.publish publishing core=awholynewcollection_0_shard1_replica3 state=down
[junit4:junit4]   2> 2445064 T4595 oasc.ZkController.publish publishing core=awholynewcollection_0_shard1_replica4 state=down
[junit4:junit4]   2> 2446439 T4585 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2446442 T4585 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"127.0.0.1:50566__nodes_used_collection_shard1_replica1",
[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_replica1",
[junit4:junit4]   2> 	  "collection":"nodes_used_collection",
[junit4:junit4]   2> 	  "shard_range":null,
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:50566_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:50566"}
[junit4:junit4]   2> 2446455 T4585 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"127.0.0.1:50563__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:50563_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:50563"}
[junit4:junit4]   2> 2446467 T4585 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"127.0.0.1:50560__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:50560_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:50560"}
[junit4:junit4]   2> 2446502 T4585 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"127.0.0.1:50557__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:50557_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:50557"}
[junit4:junit4]   2> 2446518 T4585 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "numShards":"1",
[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":"awholynewcollection_0_shard1_replica1",
[junit4:junit4]   2> 	  "collection":"awholynewcollection_0",
[junit4:junit4]   2> 	  "shard_range":null,
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:50560_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:50560"}
[junit4:junit4]   2> 2446518 T4585 oasc.Overseer$ClusterStateUpdater.createCollection Create collection awholynewcollection_0 with numShards 1
[junit4:junit4]   2> 2446544 T4585 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "numShards":"1",
[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":"awholynewcollection_0_shard1_replica2",
[junit4:junit4]   2> 	  "collection":"awholynewcollection_0",
[junit4:junit4]   2> 	  "shard_range":null,
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:50553_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:50553"}
[junit4:junit4]   2> 2446556 T4585 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "numShards":"1",
[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":"awholynewcollection_0_shard1_replica3",
[junit4:junit4]   2> 	  "collection":"awholynewcollection_0",
[junit4:junit4]   2> 	  "shard_range":null,
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:50563_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:50563"}
[junit4:junit4]   2> 2446566 T4585 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":null,
[junit4:junit4]   2> 	  "numShards":"1",
[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":"awholynewcollection_0_shard1_replica4",
[junit4:junit4]   2> 	  "collection":"awholynewcollection_0",
[junit4:junit4]   2> 	  "shard_range":null,
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:50557_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:50557"}
[junit4:junit4]   2> 2446585 T4659 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> 2446585 T4589 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> 2446586 T4644 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> 2446586 T4602 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> 2446585 T4616 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> 2446585 T4630 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> 2446586 T4661 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> 2446610 T4584 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> 2446906 T4612 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:50566__nodes_used_collection_shard1_replica1, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4]   2> 2446908 T4612 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:50566__nodes_used_collection_shard1_replica1&state=recovering&nodeName=127.0.0.1:50566_&action=PREPRECOVERY&checkLive=true&core=nodes_used_collection_shard1_replica2&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2006 
[junit4:junit4]   2> 2446969 T4626 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:50557__nodes_used_collection_shard2_replica1, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4]   2> 2446970 T4626 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:50557__nodes_used_collection_shard2_replica1&state=recovering&nodeName=127.0.0.1:50557_&action=PREPRECOVERY&checkLive=true&core=nodes_used_collection_shard2_replica2&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2005 
[junit4:junit4]   2> 2447078 T4579 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica2' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1371375667015/awholynewcollection_0_shard1_replica2
[junit4:junit4]   2> 2447080 T4579 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4]   2> 2447081 T4607 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1371375671246/awholynewcollection_0_shard1_replica1
[junit4:junit4]   2> 2447082 T4607 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4]   2> 2447083 T4622 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica3' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371375673518/awholynewcollection_0_shard1_replica3
[junit4:junit4]   2> 2447084 T4622 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4]   2> 2447085 T4595 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica4' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945/awholynewcollection_0_shard1_replica4
[junit4:junit4]   2> 2447086 T4595 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4]   2> 2447090 T4595 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4]   2> 2447090 T4595 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4]   2> 2447096 T4595 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4]   2> 2447097 T4595 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4]   2> 2447105 T4595 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4]   2> 2447116 T4579 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4]   2> 2447117 T4579 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4]   2> 2447116 T4607 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 2447119 T4607 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4]   2> 2447119 T4622 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 2447120 T4622 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4]   2> 2447121 T4595 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945/awholynewcollection_0_shard1_replica4/'
[junit4:junit4]   2> 2447125 T4579 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4]   2> 2447127 T4607 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1371375671246/awholynewcollection_0_shard1_replica1/'
[junit4:junit4]   2> 2447128 T4622 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371375673518/awholynewcollection_0_shard1_replica3/'
[junit4:junit4]   2> 2447203 T4579 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4]   2> 2447208 T4579 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1371375667015/awholynewcollection_0_shard1_replica2/'
[junit4:junit4]   2> 2447495 T4607 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 2447515 T4622 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 2447536 T4579 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 2447606 T4595 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4]   2> 2447858 T4595 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 2447876 T4595 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4]   2> 2447929 T4595 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica4] Schema name=test
[junit4:junit4]   2> 2447956 T4607 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 2447962 T4607 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4]   2> 2447979 T4607 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica1] Schema name=test
[junit4:junit4]   2> 2448016 T4622 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 2448019 T4579 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 2448023 T4622 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4]   2> 2448034 T4579 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4]   2> 2448034 T4622 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica3] Schema name=test
[junit4:junit4]   2> 2448066 T4579 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica2] Schema name=test
[junit4:junit4]   2> ASYNC  NEW_CORE C2681 name=nodes_used_collection_shard1_replica1 org.apache.solr.core.SolrCore@20e726c3 url=http://127.0.0.1:50566/nodes_used_collection_shard1_replica1 node=127.0.0.1:50566_ C2681_STATE=coll:nodes_used_collection core:nodes_used_collection_shard1_replica1 props:{shard=shard1, state=recovering, core=nodes_used_collection_shard1_replica1, collection=nodes_used_collection, node_name=127.0.0.1:50566_, base_url=http://127.0.0.1:50566}
[junit4:junit4]   2> 2448920 T4656 C2681 P50566 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:50560/nodes_used_collection_shard1_replica2/ core=nodes_used_collection_shard1_replica1 - recoveringAfterStartup=true
[junit4:junit4]   2> 2448921 T4656 C2681 P50566 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica1 url=http://127.0.0.1:50566 START replicas=[http://127.0.0.1:50560/nodes_used_collection_shard1_replica2/] nUpdates=100
[junit4:junit4]   2> 2448927 T4656 C2681 P50566 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 2448928 T4656 C2681 P50566 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=nodes_used_collection_shard1_replica1
[junit4:junit4]   2> 2448928 T4656 C2681 P50566 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=nodes_used_collection_shard1_replica1
[junit4:junit4]   2> 2448929 T4656 C2681 P50566 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=nodes_used_collection_shard1_replica1
[junit4:junit4]   2> 2448930 T4656 C2681 P50566 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 2448930 T4656 C2681 P50566 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:50560/nodes_used_collection_shard1_replica2/. core=nodes_used_collection_shard1_replica1
[junit4:junit4]   2> 2448931 T4656 C2681 P50566 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C2682 name=nodes_used_collection_shard1_replica2 org.apache.solr.core.SolrCore@20b35877 url=http://127.0.0.1:50560/nodes_used_collection_shard1_replica2 node=127.0.0.1:50560_ C2682_STATE=coll:nodes_used_collection core:nodes_used_collection_shard1_replica2 props:{shard=shard1, state=active, core=nodes_used_collection_shard1_replica2, collection=nodes_used_collection, node_name=127.0.0.1:50560_, base_url=http://127.0.0.1:50560, leader=true}
[junit4:junit4]   2> 2448981 T4610 C2682 P50560 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=13 
[junit4:junit4]   2> ASYNC  NEW_CORE C2683 name=nodes_used_collection_shard2_replica1 org.apache.solr.core.SolrCore@3e1ecf6d url=http://127.0.0.1:50557/nodes_used_collection_shard2_replica1 node=127.0.0.1:50557_ C2683_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:50557_, base_url=http://127.0.0.1:50557}
[junit4:junit4]   2> 2448982 T4657 C2683 P50557 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:50563/nodes_used_collection_shard2_replica2/ core=nodes_used_collection_shard2_replica1 - recoveringAfterStartup=true
[junit4:junit4]   2> 2448983 T4657 C2683 P50557 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica1 url=http://127.0.0.1:50557 START replicas=[http://127.0.0.1:50563/nodes_used_collection_shard2_replica2/] nUpdates=100
[junit4:junit4]   2> 2448984 T4657 C2683 P50557 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 2448985 T4657 C2683 P50557 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=nodes_used_collection_shard2_replica1
[junit4:junit4]   2> 2448985 T4657 C2683 P50557 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=nodes_used_collection_shard2_replica1
[junit4:junit4]   2> 2448988 T4657 C2683 P50557 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=nodes_used_collection_shard2_replica1
[junit4:junit4]   2> 2448988 T4657 C2683 P50557 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 2448989 T4657 C2683 P50557 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:50563/nodes_used_collection_shard2_replica2/. core=nodes_used_collection_shard2_replica1
[junit4:junit4]   2> 2448989 T4657 C2683 P50557 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C2684 name=nodes_used_collection_shard2_replica2 org.apache.solr.core.SolrCore@4865fe34 url=http://127.0.0.1:50563/nodes_used_collection_shard2_replica2 node=127.0.0.1:50563_ C2684_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:50563_, base_url=http://127.0.0.1:50563, leader=true}
[junit4:junit4]   2> 2449018 T4623 C2684 P50563 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=11 
[junit4:junit4]   2> 2449022 T4609 C2682 P50560 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> ASYNC  NEW_CORE C2685 name=nodes_used_collection_shard1_replica2 org.apache.solr.core.SolrCore@20b35877 url=http://127.0.0.1:50560/nodes_used_collection_shard1_replica2 node=127.0.0.1:50560_ C2685_STATE=coll:nodes_used_collection core:nodes_used_collection_shard1_replica2 props:{shard=shard1, state=active, core=nodes_used_collection_shard1_replica2, collection=nodes_used_collection, node_name=127.0.0.1:50560_, base_url=http://127.0.0.1:50560, leader=true}
[junit4:junit4]   2> 2449082 T4609 C2685 P50560 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2b448545 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7ba3cdd4),segFN=segments_1,generation=1}
[junit4:junit4]   2> 2449083 T4609 C2685 P50560 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> ASYNC  NEW_CORE C2686 name=nodes_used_collection_shard2_replica2 org.apache.solr.core.SolrCore@4865fe34 url=http://127.0.0.1:50563/nodes_used_collection_shard2_replica2 node=127.0.0.1:50563_ C2686_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:50563_, base_url=http://127.0.0.1:50563, leader=true}
[junit4:junit4]   2> 2449084 T4624 C2686 P50563 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 2449101 T4609 C2685 P50560 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2b448545 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7ba3cdd4),segFN=segments_1,generation=1}
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2b448545 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7ba3cdd4),segFN=segments_2,generation=2}
[junit4:junit4]   2> 2449102 T4609 C2685 P50560 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4]   2> 2449105 T4609 C2685 P50560 oass.SolrIndexSearcher.<init> Opening Searcher@2507c5ce realtime
[junit4:junit4]   2> 2449105 T4609 C2685 P50560 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 2449106 T4609 C2685 P50560 oasup.LogUpdateProcessor.finish [nodes_used_collection_shard1_replica2] webapp= path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 85
[junit4:junit4]   2> ASYNC  NEW_CORE C2687 name=nodes_used_collection_shard1_replica1 org.apache.solr.core.SolrCore@20e726c3 url=http://127.0.0.1:50566/nodes_used_collection_shard1_replica1 node=127.0.0.1:50566_ C2687_STATE=coll:nodes_used_collection core:nodes_used_collection_shard1_replica1 props:{shard=shard1, state=recovering, core=nodes_used_collection_shard1_replica1, collection=nodes_used_collection, node_name=127.0.0.1:50566_, base_url=http://127.0.0.1:50566}
[junit4:junit4]   2> 2449109 T4656 C2687 P50566 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 2449111 T4656 C2687 P50566 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 2449111 T4624 C2686 P50563 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1f3910c2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@27a1dd15),segFN=segments_1,generation=1}
[junit4:junit4]   2> 2449114 T4624 C2686 P50563 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 2449119 T4612 C2685 P50560 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 2449120 T4612 C2685 P50560 oasc.SolrCore.execute [nodes_used_collection_shard1_replica2] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 2449121 T4656 C2687 P50566 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4]   2> 2449122 T4656 C2687 P50566 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 2449122 T4656 C2687 P50566 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 2449127 T4624 C2686 P50563 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1f3910c2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@27a1dd15),segFN=segments_1,generation=1}
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1f3910c2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@27a1dd15),segFN=segments_2,generation=2}
[junit4:junit4]   2> 2449129 T4624 C2686 P50563 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4]   2> 2449139 T4624 C2686 P50563 oass.SolrIndexSearcher.<init> Opening Searcher@3439636 realtime
[junit4:junit4]   2> 2449140 T4624 C2686 P50563 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 2449141 T4624 C2686 P50563 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 57
[junit4:junit4]   2> ASYNC  NEW_CORE C2688 name=nodes_used_collection_shard2_replica1 org.apache.solr.core.SolrCore@3e1ecf6d url=http://127.0.0.1:50557/nodes_used_collection_shard2_replica1 node=127.0.0.1:50557_ C2688_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:50557_, base_url=http://127.0.0.1:50557}
[junit4:junit4]   2> 2449151 T4657 C2688 P50557 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 2449152 T4657 C2688 P50557 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 2449157 T4611 C2685 P50560 oasc.SolrCore.execute [nodes_used_collection_shard1_replica2] webapp= path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=28 
[junit4:junit4]   2> 2449159 T4626 C2686 P50563 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 2449159 T4626 C2686 P50563 oasc.SolrCore.execute [nodes_used_collection_shard2_replica2] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=4 
[junit4:junit4]   2> 2449161 T4657 C2688 P50557 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4]   2> 2449161 T4657 C2688 P50557 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4]   2> 2449162 T4657 C2688 P50557 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4]   2> 2449161 T4656 C2687 P50566 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4]   2> 2449165 T4656 C2687 P50566 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1371375675754/nodes_used_collection_shard1_replica1/data/index.20130616034131626
[junit4:junit4]   2> 2449166 T4656 C2687 P50566 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@7ebdd691 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c7f8c65) fullCopy=false
[junit4:junit4]   2> 2449167 T4623 C2686 P50563 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=0 
[junit4:junit4]   2> 2449170 T4657 C2688 P50557 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4]   2> 2449171 T4610 C2685 P50560 oasc.SolrCore.execute [nodes_used_collection_shard1_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> 2449174 T4657 C2688 P50557 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945/nodes_used_collection_shard2_replica1/data/index.20130616034131633
[junit4:junit4]   2> 2449174 T4657 C2688 P50557 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@5a2e89f4 lockFactory=org.apache.lucene.store.NativeFSLockFactory@17b32f9c) fullCopy=false
[junit4:junit4]   2> 2449186 T4625 C2686 P50563 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> 2449189 T4656 C2687 P50566 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> 2449190 T4657 C2688 P50557 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4]   2> ASYNC  NEW_CORE C2689 name=nodes_used_collection_shard1_replica1 org.apache.solr.core.SolrCore@20e726c3 url=http://127.0.0.1:50566/nodes_used_collection_shard1_replica1 node=127.0.0.1:50566_ C2689_STATE=coll:nodes_used_collection core:nodes_used_collection_shard1_replica1 props:{shard=shard1, state=recovering, core=nodes_used_collection_shard1_replica1, collection=nodes_used_collection, node_name=127.0.0.1:50566_, base_url=http://127.0.0.1:50566}
[junit4:junit4]   2> 2449252 T4656 C2689 P50566 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 2449252 T4656 C2689 P50566 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=nodes_used_collection_shard1_replica1
[junit4:junit4]   2> ASYNC  NEW_CORE C2690 name=nodes_used_collection_shard2_replica1 org.apache.solr.core.SolrCore@3e1ecf6d url=http://127.0.0.1:50557/nodes_used_collection_shard2_replica1 node=127.0.0.1:50557_ C2690_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:50557_, base_url=http://127.0.0.1:50557}
[junit4:junit4]   2> 2449252 T4657 C2690 P50557 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 2449263 T4657 C2690 P50557 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=nodes_used_collection_shard2_replica1
[junit4:junit4]   2> ASYNC  NEW_CORE C2691 name=nodes_used_collection_shard1_replica1 org.apache.solr.core.SolrCore@20e726c3 url=http://127.0.0.1:50566/nodes_used_collection_shard1_replica1 node=127.0.0.1:50566_ C2691_STATE=coll:nodes_used_collection core:nodes_used_collection_shard1_replica1 props:{shard=shard1, state=recovering, core=nodes_used_collection_shard1_replica1, collection=nodes_used_collection, node_name=127.0.0.1:50566_, base_url=http://127.0.0.1:50566}
[junit4:junit4]   2> 2449404 T4656 C2691 P50566 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@a7a7ea2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7ca31792),segFN=segments_1,generation=1}
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@a7a7ea2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7ca31792),segFN=segments_2,generation=2}
[junit4:junit4]   2> 2449413 T4656 C2691 P50566 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4]   2> ASYNC  NEW_CORE C2692 name=nodes_used_collection_shard2_replica1 org.apache.solr.core.SolrCore@3e1ecf6d url=http://127.0.0.1:50557/nodes_used_collection_shard2_replica1 node=127.0.0.1:50557_ C2692_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:50557_, base_url=http://127.0.0.1:50557}
[junit4:junit4]   2> 2449419 T4657 C2692 P50557 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6ac7286a lockFactory=org.apache.lucene.store.NativeFSLockFactory@466d1116),segFN=segments_1,generation=1}
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6ac7286a lockFactory=org.apache.lucene.store.NativeFSLockFactory@466d1116),segFN=segments_2,generation=2}
[junit4:junit4]   2> 2449422 T4657 C2692 P50557 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4]   2> 2449423 T4657 C2692 P50557 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 2449423 T4657 C2692 P50557 oass.SolrIndexSearcher.<init> Opening Searcher@6f92c0e9 main
[junit4:junit4]   2> 2449424 T4656 C2691 P50566 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 2449425 T4653 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica1] Registered new searcher Searcher@6f92c0e9 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4]   2> 2449426 T4657 C2692 P50557 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945/nodes_used_collection_shard2_replica1/data/index.20130616034131633 [CachedDir<<refCount=0;path=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945/nodes_used_collection_shard2_replica1/data/index.20130616034131633;done=true>>]
[junit4:junit4]   2> 2449427 T4657 C2692 P50557 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945/nodes_used_collection_shard2_replica1/data/index.20130616034131633
[junit4:junit4]   2> 2449427 T4657 C2692 P50557 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945/nodes_used_collection_shard2_replica1/data/index.20130616034131633
[junit4:junit4]   2> 2449428 T4657 C2692 P50557 oasc.RecoveryStrategy.replay No replay needed. core=nodes_used_collection_shard2_replica1
[junit4:junit4]   2> 2449428 T4657 C2692 P50557 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=nodes_used_collection_shard2_replica1
[junit4:junit4]   2> 2449429 T4657 C2692 P50557 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica1 state=active
[junit4:junit4]   2> 2449427 T4656 C2691 P50566 oass.SolrIndexSearcher.<init> Opening Searcher@2a4f7a31 main
[junit4:junit4]   2> 2449433 T4650 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica1] Registered new searcher Searcher@2a4f7a31 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4]   2> 2449434 T4657 C2692 P50557 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=nodes_used_collection_shard2_replica1
[junit4:junit4]   2> 2449437 T4656 C2691 P50566 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1371375675754/nodes_used_collection_shard1_replica1/data/index.20130616034131626 [CachedDir<<refCount=0;path=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1371375675754/nodes_used_collection_shard1_replica1/data/index.20130616034131626;done=true>>]
[junit4:junit4]   2> 2449437 T4656 C2691 P50566 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1371375675754/nodes_used_collection_shard1_replica1/data/index.20130616034131626
[junit4:junit4]   2> 2449438 T4656 C2691 P50566 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1371375675754/nodes_used_collection_shard1_replica1/data/index.20130616034131626
[junit4:junit4]   2> 2449438 T4656 C2691 P50566 oasc.RecoveryStrategy.replay No replay needed. core=nodes_used_collection_shard1_replica1
[junit4:junit4]   2> 2449438 T4656 C2691 P50566 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=nodes_used_collection_shard1_replica1
[junit4:junit4]   2> 2449439 T4656 C2691 P50566 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=active
[junit4:junit4]   2> 2449442 T4656 C2691 P50566 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=nodes_used_collection_shard1_replica1
[junit4:junit4]   2> 2449727 T4585 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2449729 T4585 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"127.0.0.1:50557__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:50557_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:50557"}
[junit4:junit4]   2> 2449739 T4585 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"127.0.0.1:50566__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:50566_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:50566"}
[junit4:junit4]   2> 2449781 T4616 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> 2449782 T4589 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> 2449782 T4602 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> 2449782 T4644 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> 2449782 T4661 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> 2449782 T4659 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> 2449782 T4630 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> 2449798 T4584 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> 2452051 T4595 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 2452102 T4607 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 2452132 T4595 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 2452144 T4595 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 2452164 T4607 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 2452193 T4607 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 2452266 T4595 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 2452282 T4595 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 2452289 T4607 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 2452296 T4595 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 2452314 T4595 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 2452316 T4595 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 2452316 T4595 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 2452320 T4607 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 2452336 T4595 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 2452337 T4595 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 2452338 T4595 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 2452338 T4595 oasc.SolrCore.<init> [awholynewcollection_0_shard1_replica4] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945/awholynewcollection_0_shard1_replica4/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945/awholynewcollection_0_shard1_replica4/data/
[junit4:junit4]   2> 2452339 T4595 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2060182
[junit4:junit4]   2> 2452340 T4595 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 2452347 T4607 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 2452358 T4595 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945/awholynewcollection_0_shard1_replica4/data
[junit4:junit4]   2> 2452395 T4622 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 2452399 T4579 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 2452405 T4595 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945/awholynewcollection_0_shard1_replica4/data/index/
[junit4:junit4]   2> 2452405 T4595 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard1_replica4] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945/awholynewcollection_0_shard1_replica4/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 2452410 T4622 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 2452412 T4595 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945/awholynewcollection_0_shard1_replica4/data/index
[junit4:junit4]   2> 2452412 T4607 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 2452415 T4607 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 2452416 T4607 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 2452418 T4579 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 2452423 T4579 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 2452425 T4622 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 2452431 T4595 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@12377a35 lockFactory=org.apache.lucene.store.NativeFSLockFactory@c8f27f),segFN=segments_1,generation=1}
[junit4:junit4]   2> 2452432 T4595 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 2452441 T4595 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 2452443 T4595 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 2452447 T4595 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 2452449 T4595 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 2452452 T4595 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 2452453 T4595 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 2452453 T4595 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 2452459 T4595 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 2452460 T4595 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 2452483 T4607 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 2452501 T4607 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 2452502 T4607 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 2452504 T4607 oasc.SolrCore.<init> [awholynewcollection_0_shard1_replica1] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1371375671246/awholynewcollection_0_shard1_replica1/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1371375671246/awholynewcollection_0_shard1_replica1/data/
[junit4:junit4]   2> 2452505 T4607 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2060182
[junit4:junit4]   2> 2452507 T4607 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 2452510 T4607 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1371375671246/awholynewcollection_0_shard1_replica1/data
[junit4:junit4]   2> 2452513 T4607 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1371375671246/awholynewcollection_0_shard1_replica1/data/index/
[junit4:junit4]   2> 2452514 T4607 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard1_replica1] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1371375671246/awholynewcollection_0_shard1_replica1/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 2452517 T4607 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1371375671246/awholynewcollection_0_shard1_replica1/data/index
[junit4:junit4]   2> 2452532 T4595 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 2452534 T4607 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@9953734 lockFactory=org.apache.lucene.store.NativeFSLockFactory@5dfc64c0),segFN=segments_1,generation=1}
[junit4:junit4]   2> 2452535 T4607 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 2452544 T4607 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 2452546 T4607 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 2452550 T4595 oass.SolrIndexSearcher.<init> Opening Searcher@51a5c1cc main
[junit4:junit4]   2> 2452551 T4595 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371375668945/awholynewcollection_0_shard1_replica4/data/tlog
[junit4:junit4]   2> 2452553 T4595 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 2452554 T4595 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 2452559 T4607 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 2452560 T4622 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 2452560 T4607 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 2452562 T4607 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 2452563 T4607 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 2452563 T4607 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 2452565 T4607 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 2452567 T4607 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 2452569 T4666 oasc.SolrCore.registerSearcher [awholynewcollection_0_shard1_replica4] Registered new searcher Searcher@51a5c1cc main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 2452597 T4607 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 2452610 T4595 oasc.CoreContainer.registerCore registering core: awholynewcollection_0_shard1_replica4
[junit4:junit4]   2> 2452612 T4595 oasc.ZkController.register Register replica - core:awholynewcollection_0_shard1_replica4 address:http://127.0.0.1:50557 collection:awholynewcollection_0 shard:shard1
[junit4:junit4]   2> 2452615 T4607 oass.SolrIndexSearcher.<init> Opening Searcher@7081e42c main
[junit4:junit4]   2> 2452616 T4607 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1371375671246/awholynewcollection_0_shard1_replica1/data/tlog
[junit4:junit4]   2> 2452623 T4622 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 2452628 T4607 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 2452629 T4595 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0/leader_elect/shard1/election
[junit4:junit4]   2> 2452630 T4607 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 2452638 T4667 oasc.SolrCore.registerSearcher [awholynewcollection_0_shard1_replica1] Registered new searcher Searcher@7081e42c main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 2452670 T4607 oasc.CoreContainer.registerCore registering core: awholynewcollection_0_shard1_replica1
[junit4:junit4]   2> 2452672 T4607 oasc.ZkController.register Register replica - core:awholynewcollection_0_shard1_replica1 address:http://127.0.0.1:50560 collection:awholynewcollection_0 shard:shard1
[junit4:junit4]   2> 2452671 T4622 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 2452670 T4579 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 2452678 T4607 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0/leader_elect/shard1/election
[junit4:junit4]   2> 2452693 T4622 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 2452705 T4622 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 2452707 T4622 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 2452696 T4579 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 2452719 T4595 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 2452720 T4622 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 2452732 T4622 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 2452733 T4622 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 2452735 T4622 oasc.SolrCore.<init> [awholynewcollection_0_shard1_replica3] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371375673518/awholynewcollection_0_shard1_replica3/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371375673518/awholynewcollection_0_shard1_replica3/data/
[junit4:junit4]   2> 2452735 T4622 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2060182
[junit4:junit4]   2> 2452736 T4622 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 2452730 T4579 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 2452739 T4622 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371375673518/awholynewcollection_0_shard1_replica3/data
[junit4:junit4]   2> 2452740 T4622 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371375673518/awholynewcollection_0_shard1_replica3/data/index/
[junit4:junit4]   2> 2452740 T4622 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard1_replica3] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371375673518/awholynewcollection_0_shard1_replica3/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 2452741 T4622 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371375673518/awholynewcollection_0_shard1_replica3/data/index
[junit4:junit4]   2> 2452749 T4579 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 2452750 T4579 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 2452755 T4579 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 2452761 T4622 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@12e01a41 lockFactory=org.apache.lucene.store.NativeFSLockFactory@445416ac),segFN=segments_1,generation=1}
[junit4:junit4]   2> 2452762 T4622 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 2452769 T4579 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 2452772 T4579 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 2452773 T4579 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 2452774 T4579 oasc.SolrCore.<init> [awholynewcollection_0_shard1_replica2] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1371375667015/awholynewcollection_0_shard1_replica2/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1371375667015/awholynewcollection_0_shard1_replica2/data/
[junit4:junit4]   2> 2452775 T4579 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2060182
[junit4:junit4]   2> 2452777 T4579 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 2452782 T4622 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 2452784 T4622 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 2452787 T4622 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 2452789 T4622 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 2452791 T4579 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1371375667015/awholynewcollection_0_shard1_replica2/data
[junit4:junit4]   2> 2452801 T4579 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1371375667015/awholynewcollection_0_shard1_replica2/data/index/
[junit4:junit4]   2> 2452803 T4579 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard1_replica2] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1371375667015/awholynewcollection_0_shard1_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 2452802 T4622 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 2452811 T4622 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 2452813 T4622 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 2452806 T4579 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1371375667015/awholynewcollection_0_shard1_replica2/data/index
[junit4:junit4]   2> 2452815 T4622 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 2452816 T4595 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=4 found=2 timeoutin=179991
[junit4:junit4]   2> 2452821 T4622 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 2452822 T4579 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@74d7cfd5 lockFactory=org.apache.lucene.store.NativeFSLockFactory@541ecdc0),segFN=segments_1,generation=1}
[junit4:junit4]   2> 2452823 T4579 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 2452828 T4579 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 2452829 T4579 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 2452832 T4579 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 2452835 T4579 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 2452837 T4579 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 2452839 T4579 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 2452841 T4579 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 2452853 T4579 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 2452855 T4579 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 2452863 T4579 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 2452849 T4622 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 2452912 T4579 oass.SolrIndexSearcher.<init> Opening Searcher@5348b78b main
[junit4:junit4]   2> 2452913 T4579 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1371375667015/awholynewcollection_0_shard1_replica2/data/tlog
[junit4:junit4]   2> 2452915 T4579 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 2452916 T4579 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 2452922 T4668 oasc.SolrCore.registerSearcher [awholynewcollection_0_shard1_replica2] Registered new searcher Searcher@5348b78b main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 2452924 T4622 oass.SolrIndexSearcher.<init> Opening Searcher@295fecea main
[junit4:junit4]   2> 2452925 T4622 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371375673518/awholynewcollection_0_shard1_replica3/data/tlog
[junit4:junit4]   2> 2452929 T4585 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2452932 T4622 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 2452933 T4622 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 2452940 T4579 oasc.CoreContainer.registerCore registering core: awholynewcollection_0_shard1_replica2
[junit4:junit4]   2> 2452944 T4579 oasc.ZkController.register Register replica - core:awholynewcollection_0_shard1_replica2 address:http://127.0.0.1:50553 collection:awholynewcollection_0 shard:shard1
[junit4:junit4]   2> 2452969 T4669 oasc.SolrCore.registerSearcher [awholynewcollection_0_shard1_replica3] Registered new searcher Searcher@295fecea main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 2452976 T4622 oasc.CoreContainer.registerCore registering core: awholynewcollection_0_shard1_replica3
[junit4:junit4]   2> 2452977 T4622 oasc.ZkController.register Register replica - core:awholynewcollection_0_shard1_replica3 address:http://127.0.0.1:50563 collection:awholynewcollection_0 shard:shard1
[junit4:junit4]   2> 2452987 T4616 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> 2452989 T4630 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> 2452991 T4644 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> 2452993 T4659 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> 2452993 T4602 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> 2452994 T4589 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> 2452995 T4661 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> 2452996 T4584 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> 2453324 T4595 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 2453324 T4595 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 2453325 T4595 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50557/awholynewcollection_0_shard1_replica4/
[junit4:junit4]   2> 2453325 T4595 oasu.PeerSync.sync PeerSync: core=awholynewcollection_0_shard1_replica4 url=http://127.0.0.1:50557 START replicas=[http://127.0.0.1:50560/awholynewcollection_0_shard1_replica1/, http://127.0.0.1:50553/awholynewcollection_0_shard1_replica2/, http://127.0.0.1:50563/awholynewcollection_0_shard1_replica3/] nUpdates=100
[junit4:junit4]   2> 2453328 T4595 oasu.PeerSync.sync PeerSync: core=awholynewcollection_0_shard1_replica4 url=http://127.0.0.1:50557 DONE.  We have no versions.  sync failed.
[junit4:junit4]   2> 2453328 T4595 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4]   2> 2453329 T4595 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> 2453330 T4595 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50557/awholynewcollection_0_shard1_replica4/
[junit4:junit4]   2> 2453330 T4595 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0/leaders/shard1
[junit4:junit4]   2> ASYNC  NEW_CORE C2693 name=awholynewcollection_0_shard1_replica1 org.apache.solr.core.SolrCore@3dbb8662 url=http://127.0.0.1:50560/awholynewcollection_0_shard1_replica1 node=127.0.0.1:50560_ C2693_STATE=coll:awholynewcollection_0 core:awholynewcollection_0_shard1_replica1 props:{shard=shard1, state=down, core=awholynewcollection_0_shard1_replica1, collection=awholynewcollection_0, node_name=127.0.0.1:50560_, base_url=http://127.0.0.1:50560}
[junit4:junit4]   2> 2453363 T4609 C2693 P50560 oasc.SolrCore.execute [awholynewcollection_0_shard1_replica1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=10 
[junit4:junit4]   2> ASYNC  NEW_CORE C2694 name=awholynewcollection_0_shard1_replica3 org.apache.solr.core.SolrCore@67fb3d91 url=http://127.0.0.1:50563/awholynewcollection_0_shard1_replica3 node=127.0.0.1:50563_ C2694_STATE=coll:awholynewcollection_0 core:awholynewcollection_0_shard1_replica3 props:{shard=shard1, state=down, core=awholynewcollection_0_shard1_replica3, collection=awholynewcollection_0, node_name=127.0.0.1:50563_, base_url=http://127.0.0.1:50563}
[junit4:junit4]   2> 2453419 T4624 C2694 P50563 oasc.SolrCore.execute [awholynewcollection_0_shard1_replica3] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=23 
[junit4:junit4]   2> ASYNC  NEW_CORE C2695 name=awholynewcollection_0_shard1_replica2 org.apache.solr.core.SolrCore@7a3bad89 url=http://127.0.0.1:50553/awholynewcollection_0_shard1_replica2 node=127.0.0.1:50553_ C2695_STATE=coll:awholynewcollection_0 core:awholynewcollection_0_shard1_replica2 props:{shard=shard1, state=down, core=awholynewcollection_0_shard1_replica2, collection=awholynewcollection_0, node_name=127.0.0.1:50553_, base_url=http://127.0.0.1:50553}
[junit4:junit4]   2> 2453426 T4580 C2695 P50553 oasc.SolrCore.execute [awholynewcollection_0_shard1_replica2] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=2 
[junit4:junit4]   2> 2454521 T4585 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2454541 T4630 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> 2454542 T4616 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> 2454542 T4644 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> 2454543 T4659 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> 2454543 T4589 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> 2454544 T4661 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> 2454548 T4602 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> 2454544 T4584 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> 2454578 T4579 oasc.ZkController.register We are http://127.0.0.1:50553/awholynewcollection_0_shard1_replica2/ and leader is http://127.0.0.1:50557/awholynewcollection_0_shard1_replica4/
[junit4:junit4]   2> 2454579 T4579 oasc.ZkController.register No LogReplay needed for core=awholynewcollection_0_shard1_replica2 baseURL=http://127.0.0.1:50553
[junit4:junit4]   2> 2454580 T4579 oasc.ZkController.checkRecovery Core needs to recover:awholynewcollection_0_shard1_replica2
[junit4:junit4]   2> 2454580 T4579 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> 2454582 T4673 C2695 P50553 oasc.RecoveryStrategy.run Starting recovery process.  core=awholynewcollection_0_shard1_replica2 recoveringAfterStartup=true
[junit4:junit4]   2> 2454583 T4673 C2695 P50553 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 2454584 T4673 C2695 P50553 oasc.ZkController.publish publishing core=awholynewcollection_0_shard1_replica2 state=recovering
[junit4:junit4]   2> 2454588 T4579 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2454590 T4622 oasc.ZkController.register We are http://127.0.0.1:50563/awholynewcollection_0_shard1_replica3/ and leader is http://127.0.0.1:50557/awholynewcollection_0_shard1_replica4/
[junit4:junit4]   2> 2454591 T4622 oasc.ZkController.register No LogReplay needed for core=awholynewcollection_0_shard1_replica3 baseURL=http://127.0.0.1:50563
[junit4:junit4]   2> 2454591 T4622 oasc.ZkController.checkRecovery Core needs to recover:awholynewcollection_0_shard1_replica3
[junit4:junit4]   2> 2454592 T4622 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> 2454593 T4674 C2694 P50563 oasc.RecoveryStrategy.run Starting recovery process.  core=awholynewcollection_0_shard1_replica3 recoveringAfterStartup=true
[junit4:junit4]   2> 2454593 T4674 C2694 P50563 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 2454595 T4674 C2694 P50563 oasc.ZkController.publish publishing core=awholynewcollection_0_shard1_replica3 state=re

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

d type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   2> 2956830 T5776 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 2956831 T5776 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 2956836 T5776 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@7e19fbf1
[junit4:junit4]   2> 2956878 T5776 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=43,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=37,cumulative_deletesById=23,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4]   2> 2956880 T5776 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 2956880 T5776 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 2956881 T5776 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 2956884 T5776 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 2956884 T5776 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4]   2> 2956885 T5776 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.RecoveryZkTest-1371376077269/jetty2 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.RecoveryZkTest-1371376077269/jetty2;done=false>>]
[junit4:junit4]   2> 2956885 T5776 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.RecoveryZkTest-1371376077269/jetty2
[junit4:junit4]   2> 2956886 T5776 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.RecoveryZkTest-1371376077269/jetty2/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.RecoveryZkTest-1371376077269/jetty2/index;done=false>>]
[junit4:junit4]   2> 2956887 T5776 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.RecoveryZkTest-1371376077269/jetty2/index
[junit4:junit4]   2> 2956889 T5875 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89874502601080842-127.0.0.1:51011_-n_0000000003) am no longer a leader.
[junit4:junit4]   2> 2956913 T5776 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4]   2> 2956977 T5818 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 2956978 T5818 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 2956978 T5818 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 2956995 T5776 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4]   2> 2956999 T5776 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:51001 51001
[junit4:junit4]   1> client port:0.0.0.0/0.0.0.0:0
[junit4:junit4]   1> safe stop:
[junit4:junit4]   1> safe stop:
[junit4:junit4]   1> safe stop:
[junit4:junit4]   1> safe stop:
[junit4:junit4]   2> 2957118 T5190 oasc.OverseerCollectionProcessor.run WARN Overseer cannot talk to ZK
[junit4:junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=RecoveryZkTest -Dtests.method=testDistribSearch -Dtests.seed=CA7940D8D7D1E2D2 -Dtests.slow=true -Dtests.locale=en_ZA -Dtests.timezone=America/Santa_Isabel -Dtests.file.encoding=US-ASCII
[junit4:junit4] FAILURE  122s | RecoveryZkTest.testDistribSearch <<<
[junit4:junit4]    > Throwable #1: java.lang.AssertionError: expected:<154> but was:<26>
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([CA7940D8D7D1E2D2:4B9FCEC0A08E82EE]:0)
[junit4:junit4]    > 	at org.apache.solr.cloud.RecoveryZkTest.doTest(RecoveryZkTest.java:108)
[junit4:junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:815)
[junit4:junit4]    > 	at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   2> 2957122 T5776 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4]   2> 122335 T5775 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
[junit4:junit4]   2> 2958195 T5858 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> 2958195 T5858 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   2> 2958196 T5858 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4]   2> NOTE: test params are: codec=Lucene41, sim=DefaultSimilarity, locale=en_ZA, timezone=America/Santa_Isabel
[junit4:junit4]   2> NOTE: Mac OS X 10.8.4 x86_64/Oracle Corporation 1.7.0_21 (64-bit)/cpus=2,threads=3,free=107579744,total=375324672
[junit4:junit4]   2> NOTE: All tests run in this JVM: [TestFastOutputStream, SearchHandlerTest, TestSort, ChaosMonkeyShardSplitTest, TestFieldCollectionResource, DateMathParserTest, TestIndexingPerformance, SolrIndexSplitterTest, TestDynamicFieldResource, BinaryUpdateRequestHandlerTest, BasicDistributedZk2Test, LukeRequestHandlerTest, QueryElevationComponentTest, DocumentBuilderTest, TestFiltering, CacheHeaderTest, SolrTestCaseJ4Test, FileUtilsTest, QueryEqualityTest, TestFaceting, TestSchemaResource, TestMultiCoreConfBootstrap, SolrRequestParserTest, SimplePostToolTest, SuggesterWFSTTest, PrimitiveFieldTypeTest, URLClassifyProcessorTest, SOLR749Test, SyncSliceTest, CSVRequestHandlerTest, TestCloudManagedSchema, TestLFUCache, TestAtomicUpdateErrorCases, TestWordDelimiterFilterFactory, TestFieldTypeResource, TestHashPartitioner, TestSchemaSimilarityResource, TestRemoteStreaming, TestCloudManagedSchemaAddField, TestRecovery, SystemInfoHandlerTest, TestSolrQueryParserResource, DocValuesTest, SpellingQueryConverterTest, PreAnalyzedUpdateProcessorTest, TestReplicationHandler, TestIBSimilarityFactory, ClusterStateUpdateTest, LeaderElectionTest, OverseerCollectionProcessorTest, SpatialFilterTest, NoCacheHeaderTest, TestSolrQueryParserDefaultOperatorResource, TestDynamicFieldCollectionResource, TestCopyFieldCollectionResource, TestComponentsName, TestDistributedSearch, TestCSVResponseWriter, TestSchemaVersionResource, BasicDistributedZkTest, DOMUtilTest, TestSolrXml, TestValueSourceCache, ScriptEngineTest, RequiredFieldsTest, SuggesterTest, TestPropInjectDefaults, TestLazyCores, TestSystemIdResolver, ShardRoutingCustomTest, TestManagedSchemaFieldResource, HighlighterConfigTest, SoftAutoCommitTest, TestJmxIntegration, ChaosMonkeySafeLeaderTest, TestSearchPerf, CircularListTest, TermVectorComponentDistributedTest, IndexSchemaTest, TestSolr4Spatial, DistributedSpellCheckComponentTest, SolrCmdDistributorTest, TestArbitraryIndexDir, TestUtils, TestQueryUtils, SolrCoreTest, AliasIntegrationTest, CurrencyFieldOpenExchangeTest, TestPerFieldSimilarity, DirectSolrConnectionTest, TestQueryTypes, TestShardHandlerFactory, TestLRUCache, ShowFileRequestHandlerTest, TestPropInject, JsonLoaderTest, BasicFunctionalityTest, DirectSolrSpellCheckerTest, SolrCoreCheckLockOnStartupTest, NumericFieldsTest, IndexSchemaRuntimeFieldTest, IndexReaderFactoryTest, TermsComponentTest, CoreContainerCoreInitFailuresTest, TestStressLucene, UUIDFieldTest, PingRequestHandlerTest, ExternalFileFieldSortTest, DisMaxRequestHandlerTest, SolrIndexConfigTest, LeaderElectionIntegrationTest, RequestHandlersTest, TestReversedWildcardFilterFactory, TestUniqueKeyFieldResource, TestManagedSchema, LoggingHandlerTest, TestConfig, SimpleFacetsTest, PathHierarchyTokenizerFactoryTest, TestClassNameShortening, ShardSplitTest, DateFieldTest, TestNumberUtils, MoreLikeThisHandlerTest, TestSolrXMLSerializer, ZkControllerTest, DirectUpdateHandlerTest, TestFunctionQuery, QueryResultKeyTest, JSONWriterTest, FieldMutatingUpdateProcessorTest, TestCoreContainer, StandardRequestHandlerTest, CurrencyFieldXmlFileTest, ZkNodePropsTest, TestCodecSupport, XmlUpdateRequestHandlerTest, TestGroupingSearch, MBeansHandlerTest, DistanceFunctionTest, CachingDirectoryFactoryTest, UnloadDistributedZkTest, CollectionsAPIDistributedZkTest, OpenCloseCoreStressTest, OverseerTest, ShardRoutingTest, BasicZkTest, RecoveryZkTest]
[junit4:junit4] Completed in 123.69s, 1 test, 1 failure <<< FAILURES!

[...truncated 442 lines...]
BUILD FAILED
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/build.xml:386: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/build.xml:366: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/build.xml:39: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build.xml:181: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/common-build.xml:437: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:1243: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:887: There were test failures: 296 suites, 1243 tests, 1 error, 1 failure, 18 ignored (6 assumptions)

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



Mime
View raw message