You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/06/20 10:37:23 UTC
[JENKINS] Lucene-Solr-trunk-MacOSX (64bit/jdk1.7.0) - Build # 579 -
Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-MacOSX/579/
Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseG1GC
2 tests failed.
REGRESSION: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testDistribSearch
Error Message:
collection already exists: awholynewcollection_0
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: collection already exists: awholynewcollection_0
at __randomizedtesting.SeedInfo.seed([C44103AB69D2E3:8122CF1BDC36B2DF]: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:313)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1455)
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:835)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java: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)
REGRESSION: org.apache.solr.cloud.SyncSliceTest.testDistribSearch
Error Message:
shard1 is not consistent. Got 305 from http://127.0.0.1:49525/xm_bai/y/collection1lastClient and got 267 from http://127.0.0.1:49532/xm_bai/y/collection1
Stack Trace:
java.lang.AssertionError: shard1 is not consistent. Got 305 from http://127.0.0.1:49525/xm_bai/y/collection1lastClient and got 267 from http://127.0.0.1:49532/xm_bai/y/collection1
at __randomizedtesting.SeedInfo.seed([C44103AB69D2E3:8122CF1BDC36B2DF]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1018)
at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:238)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java: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 9231 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4:junit4] 2> 645744 T785 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /hm_dlx/z
[junit4:junit4] 2> 645787 T785 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-1371714255860
[junit4:junit4] 2> 645790 T785 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 645791 T786 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 645807 T785 oasc.ZkTestServer.run start zk server on port:49392
[junit4:junit4] 2> 645814 T785 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 645854 T792 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3cc05349 name:ZooKeeperConnection Watcher:127.0.0.1:49392 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 645855 T785 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 645855 T785 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 645893 T785 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 645900 T794 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@17deda19 name:ZooKeeperConnection Watcher:127.0.0.1:49392/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 645900 T785 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 645901 T785 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 645914 T785 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 645925 T785 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 645939 T785 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 645948 T785 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> 645949 T785 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 645964 T785 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> 645965 T785 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 645977 T785 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> 645979 T785 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 645992 T785 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> 645999 T785 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 646007 T785 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> 646008 T785 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 646020 T785 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> 646021 T785 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 646030 T785 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> 646031 T785 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 646041 T785 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> 646042 T785 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 646050 T785 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> 646051 T785 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 646670 T785 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 646696 T785 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49395
[junit4:junit4] 2> 646697 T785 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 646698 T785 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 646698 T785 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-1371714256139
[junit4:junit4] 2> 646699 T785 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-1371714256139/solr.xml
[junit4:junit4] 2> 646700 T785 oasc.CoreContainer.<init> New CoreContainer 821461936
[junit4:junit4] 2> 646700 T785 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-1371714256139/'
[junit4:junit4] 2> 646701 T785 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-1371714256139/'
[junit4:junit4] 2> 646889 T785 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-1371714256139
[junit4:junit4] 2> 646892 T785 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-1371714256139/collection1
[junit4:junit4] 2> 646893 T785 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-1371714256139/collection1/conf
[junit4:junit4] 2> 647088 T785 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-1371714256139/collection1/conf/xslt
[junit4:junit4] 2> 647092 T785 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-1371714256139/collection1/lib
[junit4:junit4] 2> 647099 T785 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-1371714256139/collection1/lib/classes
[junit4:junit4] 2> 647102 T785 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-1371714256139/conf/core.properties, adding to cores
[junit4:junit4] 2> 647118 T785 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 647121 T785 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 647125 T785 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 647126 T785 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 647127 T785 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 647127 T785 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 647128 T785 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 647128 T785 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 647129 T785 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 647129 T785 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 647159 T785 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 647160 T785 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49392/solr
[junit4:junit4] 2> 647160 T785 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 647171 T785 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 647174 T805 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@733ef04 name:ZooKeeperConnection Watcher:127.0.0.1:49392 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 647174 T785 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 647182 T785 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 647213 T785 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 647217 T807 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2f412d31 name:ZooKeeperConnection Watcher:127.0.0.1:49392/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 647238 T785 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 647255 T785 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 647271 T785 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 647282 T785 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 647291 T785 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49395_hm_dlx%2Fz
[junit4:junit4] 2> 647295 T785 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49395_hm_dlx%2Fz
[junit4:junit4] 2> 647307 T785 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 647325 T785 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 647337 T785 oasc.Overseer.start Overseer (id=89896665472696323-127.0.0.1:49395_hm_dlx%2Fz-n_0000000000) starting
[junit4:junit4] 2> 647349 T785 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 647363 T809 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 647367 T785 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 647379 T785 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 647387 T785 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 647406 T808 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 647409 T785 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 647410 T785 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 647414 T785 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 647443 T785 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 647446 T785 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 647453 T812 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6fb79bf1 name:ZooKeeperConnection Watcher:127.0.0.1:49392/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 647453 T785 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 647463 T785 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 647473 T785 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 648043 T785 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 648052 T785 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49399
[junit4:junit4] 2> 648053 T785 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 648054 T785 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 648054 T785 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-1371714257544
[junit4:junit4] 2> 648055 T785 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-1371714257544/solr.xml
[junit4:junit4] 2> 648056 T785 oasc.CoreContainer.<init> New CoreContainer 1376401576
[junit4:junit4] 2> 648057 T785 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-1371714257544/'
[junit4:junit4] 2> 648057 T785 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-1371714257544/'
[junit4:junit4] 2> 648239 T785 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-1371714257544
[junit4:junit4] 2> 648241 T785 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-1371714257544/collection1
[junit4:junit4] 2> 648242 T785 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-1371714257544/collection1/conf
[junit4:junit4] 2> 648437 T785 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-1371714257544/collection1/conf/xslt
[junit4:junit4] 2> 648443 T785 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-1371714257544/collection1/lib
[junit4:junit4] 2> 648445 T785 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-1371714257544/collection1/lib/classes
[junit4:junit4] 2> 648448 T785 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-1371714257544/conf/core.properties, adding to cores
[junit4:junit4] 2> 648469 T785 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 648470 T785 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 648471 T785 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 648471 T785 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 648472 T785 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 648472 T785 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 648473 T785 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 648474 T785 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 648475 T785 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 648476 T785 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 648502 T785 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 648503 T785 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49392/solr
[junit4:junit4] 2> 648503 T785 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 648506 T785 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 648513 T823 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@53d7ac21 name:ZooKeeperConnection Watcher:127.0.0.1:49392 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 648513 T785 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 648521 T785 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 648549 T785 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 648555 T825 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@29783b83 name:ZooKeeperConnection Watcher:127.0.0.1:49392/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 648556 T785 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 648573 T785 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 649587 T785 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49399_hm_dlx%2Fz
[junit4:junit4] 2> 649592 T785 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49399_hm_dlx%2Fz
[junit4:junit4] 2> 649608 T825 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 649616 T812 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 649617 T807 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 649625 T785 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 649626 T785 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 649626 T785 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 650218 T785 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 650228 T785 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49402
[junit4:junit4] 2> 650229 T785 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 650230 T785 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 650231 T785 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-1371714259723
[junit4:junit4] 2> 650231 T785 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-1371714259723/solr.xml
[junit4:junit4] 2> 650232 T785 oasc.CoreContainer.<init> New CoreContainer 2029497577
[junit4:junit4] 2> 650233 T785 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-1371714259723/'
[junit4:junit4] 2> 650233 T785 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-1371714259723/'
[junit4:junit4] 2> 650413 T785 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-1371714259723
[junit4:junit4] 2> 650415 T785 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-1371714259723/collection1
[junit4:junit4] 2> 650417 T785 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-1371714259723/collection1/conf
[junit4:junit4] 2> 650600 T785 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-1371714259723/collection1/conf/xslt
[junit4:junit4] 2> 650605 T785 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-1371714259723/collection1/lib
[junit4:junit4] 2> 650607 T785 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-1371714259723/collection1/lib/classes
[junit4:junit4] 2> 650610 T785 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-1371714259723/conf/core.properties, adding to cores
[junit4:junit4] 2> 650625 T785 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 650625 T785 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 650627 T785 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 650627 T785 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 650628 T785 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 650629 T785 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 650630 T785 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 650630 T785 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 650631 T785 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 650632 T785 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 650664 T785 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 650665 T785 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49392/solr
[junit4:junit4] 2> 650665 T785 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 650668 T785 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 650673 T837 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@32bc46e name:ZooKeeperConnection Watcher:127.0.0.1:49392 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 650674 T785 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 650680 T785 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 650708 T785 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 650715 T839 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5431939f name:ZooKeeperConnection Watcher:127.0.0.1:49392/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 650716 T785 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 650737 T785 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 651750 T785 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49402_hm_dlx%2Fz
[junit4:junit4] 2> 651755 T785 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49402_hm_dlx%2Fz
[junit4:junit4] 2> 651768 T825 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 651768 T807 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 651773 T839 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 651781 T812 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 651788 T785 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 651789 T785 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 651790 T785 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 652399 T785 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 652406 T785 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49405
[junit4:junit4] 2> 652408 T785 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 652408 T785 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 652409 T785 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-1371714261887
[junit4:junit4] 2> 652409 T785 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-1371714261887/solr.xml
[junit4:junit4] 2> 652410 T785 oasc.CoreContainer.<init> New CoreContainer 1360569011
[junit4:junit4] 2> 652411 T785 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-1371714261887/'
[junit4:junit4] 2> 652411 T785 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-1371714261887/'
[junit4:junit4] 2> 652656 T785 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-1371714261887
[junit4:junit4] 2> 652659 T785 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-1371714261887/collection1
[junit4:junit4] 2> 652661 T785 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-1371714261887/collection1/conf
[junit4:junit4] 2> 652862 T785 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-1371714261887/collection1/conf/xslt
[junit4:junit4] 2> 652870 T785 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-1371714261887/collection1/lib
[junit4:junit4] 2> 652875 T785 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-1371714261887/collection1/lib/classes
[junit4:junit4] 2> 652878 T785 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-1371714261887/conf/core.properties, adding to cores
[junit4:junit4] 2> 652893 T785 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 652894 T785 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 652895 T785 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 652895 T785 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 652896 T785 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 652896 T785 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 652897 T785 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 652898 T785 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 652898 T785 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 652899 T785 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 652930 T785 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 652931 T785 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49392/solr
[junit4:junit4] 2> 652932 T785 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 652936 T785 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 652941 T851 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2e1ad9e9 name:ZooKeeperConnection Watcher:127.0.0.1:49392 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 652942 T785 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 652949 T785 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 652972 T785 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 652979 T853 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4002bf5c name:ZooKeeperConnection Watcher:127.0.0.1:49392/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 652979 T785 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 653002 T785 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 654015 T785 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49405_hm_dlx%2Fz
[junit4:junit4] 2> 654021 T785 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49405_hm_dlx%2Fz
[junit4:junit4] 2> 654036 T853 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 654039 T812 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 654042 T807 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 654043 T839 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 654044 T825 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 654057 T785 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 654058 T785 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 654058 T785 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 654641 T785 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 654654 T785 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49408
[junit4:junit4] 2> 654656 T785 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 654657 T785 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 654658 T785 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-1371714264161
[junit4:junit4] 2> 654658 T785 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-1371714264161/solr.xml
[junit4:junit4] 2> 654659 T785 oasc.CoreContainer.<init> New CoreContainer 896071197
[junit4:junit4] 2> 654660 T785 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-1371714264161/'
[junit4:junit4] 2> 654661 T785 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-1371714264161/'
[junit4:junit4] 2> 654837 T785 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-1371714264161
[junit4:junit4] 2> 654839 T785 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-1371714264161/collection1
[junit4:junit4] 2> 654841 T785 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-1371714264161/collection1/conf
[junit4:junit4] 2> 655017 T785 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-1371714264161/collection1/conf/xslt
[junit4:junit4] 2> 655023 T785 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-1371714264161/collection1/lib
[junit4:junit4] 2> 655024 T785 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-1371714264161/collection1/lib/classes
[junit4:junit4] 2> 655027 T785 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-1371714264161/conf/core.properties, adding to cores
[junit4:junit4] 2> 655046 T785 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 655046 T785 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 655047 T785 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 655048 T785 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 655048 T785 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 655049 T785 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 655049 T785 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 655050 T785 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 655051 T785 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 655059 T785 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 655088 T785 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 655089 T785 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49392/solr
[junit4:junit4] 2> 655089 T785 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 655092 T785 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 655099 T865 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@48186010 name:ZooKeeperConnection Watcher:127.0.0.1:49392 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 655099 T785 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 655107 T785 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 655139 T785 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 655146 T867 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@48f0918a name:ZooKeeperConnection Watcher:127.0.0.1:49392/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 655146 T785 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 655164 T785 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 656176 T785 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49408_hm_dlx%2Fz
[junit4:junit4] 2> 656179 T785 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49408_hm_dlx%2Fz
[junit4:junit4] 2> 656201 T812 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 656202 T867 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 656207 T807 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 656216 T785 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 656216 T785 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 656217 T785 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 656223 T825 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 656224 T839 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 656224 T853 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 656243 T785 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 656272 T817 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=2&name=nodes_used_collection&replicationFactor=2&action=CREATE&wt=javabin&version=2
[junit4:junit4] 2> 656279 T807 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 656283 T809 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> 656283 T809 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:49399_hm_dlx%2Fz
[junit4:junit4] 2> 656284 T809 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:49408_hm_dlx%2Fz
[junit4:junit4] 2> 656285 T809 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:49395_hm_dlx%2Fz
[junit4:junit4] 2> 656286 T809 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:49405_hm_dlx%2Fz
[junit4:junit4] 2> 656305 T818 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=down
[junit4:junit4] 2> 656305 T862 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica2 state=down
[junit4:junit4] 2> 656306 T802 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica1 state=down
[junit4:junit4] 2> 656308 T846 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica2 state=down
[junit4:junit4] 2> 656511 T808 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 656513 T808 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:49399_hm_dlx%2Fz",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49399/hm_dlx/z"}
[junit4:junit4] 2> 656513 T808 oasc.Overseer$ClusterStateUpdater.createCollection Create collection nodes_used_collection with numShards 2
[junit4:junit4] 2> 656525 T808 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:49408_hm_dlx%2Fz",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49408/hm_dlx/z"}
[junit4:junit4] 2> 656535 T808 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:49405_hm_dlx%2Fz",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49405/hm_dlx/z"}
[junit4:junit4] 2> 656551 T808 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:49395_hm_dlx%2Fz",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49395/hm_dlx/z"}
[junit4:junit4] 2> 656569 T807 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> 656570 T825 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> 656572 T839 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> 656578 T853 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> 656582 T812 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> 656584 T867 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> 657315 T818 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-jetty1-1371714257544/nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 657318 T818 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 657317 T802 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-controljetty-1371714256139/nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 657320 T802 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 657316 T846 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-1371714261887/nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 657321 T846 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 657316 T862 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-jetty4-1371714264161/nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 657322 T862 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 657326 T846 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 657326 T846 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 657329 T846 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 657330 T846 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 657338 T846 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 657343 T846 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-1371714261887/nodes_used_collection_shard2_replica2/'
[junit4:junit4] 2> 657370 T818 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 657371 T818 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 657372 T862 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 657372 T862 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 657374 T802 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 657376 T802 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 657413 T802 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 657414 T818 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 657416 T862 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-1371714264161/nodes_used_collection_shard1_replica2/'
[junit4:junit4] 2> 657506 T802 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 657506 T818 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 657514 T802 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-1371714256139/nodes_used_collection_shard2_replica1/'
[junit4:junit4] 2> 657515 T818 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-1371714257544/nodes_used_collection_shard1_replica1/'
[junit4:junit4] 2> 657646 T846 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 657666 T862 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 657696 T802 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 657743 T818 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 657961 T846 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 657966 T846 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 657992 T846 oass.IndexSchema.readSchema [nodes_used_collection_shard2_replica2] Schema name=test
[junit4:junit4] 2> 658017 T862 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 658050 T862 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 658059 T818 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 658064 T818 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 658101 T862 oass.IndexSchema.readSchema [nodes_used_collection_shard1_replica2] Schema name=test
[junit4:junit4] 2> 658105 T818 oass.IndexSchema.readSchema [nodes_used_collection_shard1_replica1] Schema name=test
[junit4:junit4] 2> 658147 T802 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 658160 T802 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 658239 T802 oass.IndexSchema.readSchema [nodes_used_collection_shard2_replica1] Schema name=test
[junit4:junit4] 2> 661518 T862 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 661589 T846 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 661594 T862 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 661617 T862 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 661669 T846 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 661684 T846 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 661769 T802 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 661818 T802 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 661899 T802 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 661894 T846 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 661878 T862 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 661916 T862 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 661935 T846 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 661941 T862 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 661936 T818 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 661971 T862 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 661972 T862 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 661973 T862 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 661978 T846 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 661984 T862 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 661985 T862 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 661985 T862 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 661986 T862 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-jetty4-1371714264161/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-jetty4-1371714264161/nodes_used_collection_shard1_replica2/data/
[junit4:junit4] 2> 661986 T862 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5d3bd913
[junit4:junit4] 2> 661987 T862 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 661990 T846 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 662014 T846 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 662015 T846 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 661994 T862 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-1371714264161/nodes_used_collection_shard1_replica2/data
[junit4:junit4] 2> 662016 T862 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-1371714264161/nodes_used_collection_shard1_replica2/data/index/
[junit4:junit4] 2> 662016 T862 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-jetty4-1371714264161/nodes_used_collection_shard1_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 662017 T862 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-1371714264161/nodes_used_collection_shard1_replica2/data/index
[junit4:junit4] 2> 662028 T818 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 662034 T846 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 662035 T846 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 662036 T846 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 662037 T846 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-1371714261887/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-1371714261887/nodes_used_collection_shard2_replica2/data/
[junit4:junit4] 2> 662049 T846 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5d3bd913
[junit4:junit4] 2> 662050 T846 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 662062 T818 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 662066 T846 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-1371714261887/nodes_used_collection_shard2_replica2/data
[junit4:junit4] 2> 662066 T846 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-1371714261887/nodes_used_collection_shard2_replica2/data/index/
[junit4:junit4] 2> 662067 T846 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-1371714261887/nodes_used_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 662079 T846 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-1371714261887/nodes_used_collection_shard2_replica2/data/index
[junit4:junit4] 2> 662086 T862 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6058de27 lockFactory=org.apache.lucene.store.NativeFSLockFactory@17446ad5),segFN=segments_1,generation=1}
[junit4:junit4] 2> 662088 T862 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 662105 T862 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 662106 T862 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 662115 T862 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 662116 T862 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 662118 T862 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 662118 T862 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 662119 T862 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 662121 T862 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 662122 T862 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 662148 T846 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2c823d00 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1da3fa09),segFN=segments_1,generation=1}
[junit4:junit4] 2> 662150 T846 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 662156 T846 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 662157 T846 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 662158 T846 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 662161 T846 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 662163 T846 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 662164 T846 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 662164 T846 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 662166 T846 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 662173 T802 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 662175 T846 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 662208 T846 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 662211 T862 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 662257 T802 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 662269 T846 oass.SolrIndexSearcher.<init> Opening Searcher@1c5bf96d main
[junit4:junit4] 2> 662271 T846 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-1371714261887/nodes_used_collection_shard2_replica2/data/tlog
[junit4:junit4] 2> 662272 T846 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 662273 T846 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 662274 T802 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 662277 T862 oass.SolrIndexSearcher.<init> Opening Searcher@6e59278 main
[junit4:junit4] 2> 662278 T862 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-1371714264161/nodes_used_collection_shard1_replica2/data/tlog
[junit4:junit4] 2> 662286 T802 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 662286 T802 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 662287 T802 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 662289 T862 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 662290 T862 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 662298 T874 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica2] Registered new searcher Searcher@6e59278 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 662303 T862 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 662303 T862 oasc.ZkController.register Register replica - core:nodes_used_collection_shard1_replica2 address:http://127.0.0.1:49408/hm_dlx/z collection:nodes_used_collection shard:shard1
[junit4:junit4] 2> 662306 T802 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 662307 T802 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 662307 T802 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 662308 T802 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-controljetty-1371714256139/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-controljetty-1371714256139/nodes_used_collection_shard2_replica1/data/
[junit4:junit4] 2> 662309 T802 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5d3bd913
[junit4:junit4] 2> 662310 T802 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 662312 T873 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica2] Registered new searcher Searcher@1c5bf96d main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 662314 T862 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard1/election
[junit4:junit4] 2> 662321 T802 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-1371714256139/nodes_used_collection_shard2_replica1/data
[junit4:junit4] 2> 662322 T802 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-1371714256139/nodes_used_collection_shard2_replica1/data/index/
[junit4:junit4] 2> 662322 T802 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-controljetty-1371714256139/nodes_used_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 662327 T846 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 662328 T846 oasc.ZkController.register Register replica - core:nodes_used_collection_shard2_replica2 address:http://127.0.0.1:49405/hm_dlx/z collection:nodes_used_collection shard:shard2
[junit4:junit4] 2> 662338 T802 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-1371714256139/nodes_used_collection_shard2_replica1/data/index
[junit4:junit4] 2> 662340 T846 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard2/election
[junit4:junit4] 2> 662349 T802 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@25d50010 lockFactory=org.apache.lucene.store.NativeFSLockFactory@559dd738),segFN=segments_1,generation=1}
[junit4:junit4] 2> 662350 T802 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 662363 T818 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 662364 T802 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 662371 T802 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 662373 T802 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 662374 T802 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 662375 T802 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 662376 T802 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 662377 T802 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 662377 T802 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 662378 T802 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 662424 T818 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 662446 T818 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 662449 T862 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 662470 T802 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 662482 T818 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 662483 T818 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 662484 T818 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 662483 T802 oass.SolrIndexSearcher.<init> Opening Searcher@324ff339 main
[junit4:junit4] 2> 662488 T802 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-1371714256139/nodes_used_collection_shard2_replica1/data/tlog
[junit4:junit4] 2> 662489 T802 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 662490 T802 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 662482 T846 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 662501 T862 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=179985
[junit4:junit4] 2> 662502 T875 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica1] Registered new searcher Searcher@324ff339 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 662505 T818 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 662506 T818 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 662506 T818 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 662507 T818 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-jetty1-1371714257544/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-jetty1-1371714257544/nodes_used_collection_shard1_replica1/data/
[junit4:junit4] 2> 662507 T818 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5d3bd913
[junit4:junit4] 2> 662508 T818 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 662521 T818 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-1371714257544/nodes_used_collection_shard1_replica1/data
[junit4:junit4] 2> 662522 T818 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-1371714257544/nodes_used_collection_shard1_replica1/data/index/
[junit4:junit4] 2> 662523 T818 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-jetty1-1371714257544/nodes_used_collection_shard1_replica1/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 662525 T818 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-1371714257544/nodes_used_collection_shard1_replica1/data/index
[junit4:junit4] 2> 662530 T802 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 662530 T802 oasc.ZkController.register Register replica - core:nodes_used_collection_shard2_replica1 address:http://127.0.0.1:49395/hm_dlx/z collection:nodes_used_collection shard:shard2
[junit4:junit4] 2> 662534 T846 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up: total=2 found=1 timeoutin=179997
[junit4:junit4] 2> 662536 T818 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@516fc4ce lockFactory=org.apache.lucene.store.NativeFSLockFactory@4cc2e9fc),segFN=segments_1,generation=1}
[junit4:junit4] 2> 662537 T818 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 662543 T818 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 662544 T818 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 662545 T818 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 662546 T818 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 662547 T818 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 662548 T818 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 662548 T818 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 662549 T818 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 662550 T818 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 662577 T818 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 662613 T818 oass.SolrIndexSearcher.<init> Opening Searcher@6b01cc7d main
[junit4:junit4] 2> 662615 T818 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-1371714257544/nodes_used_collection_shard1_replica1/data/tlog
[junit4:junit4] 2> 662617 T818 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 662617 T818 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 662622 T876 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica1] Registered new searcher Searcher@6b01cc7d main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 662630 T818 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 662630 T818 oasc.ZkController.register Register replica - core:nodes_used_collection_shard1_replica1 address:http://127.0.0.1:49399/hm_dlx/z collection:nodes_used_collection shard:shard1
[junit4:junit4] 2> 662680 T808 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 662739 T807 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> 662740 T812 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> 662740 T867 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> 662739 T839 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> 662741 T853 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> 662742 T825 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> 663006 T862 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 663007 T862 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 663008 T862 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49408/hm_dlx/z/nodes_used_collection_shard1_replica2/
[junit4:junit4] 2> 663008 T862 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica2 url=http://127.0.0.1:49408/hm_dlx/z START replicas=[http://127.0.0.1:49399/hm_dlx/z/nodes_used_collection_shard1_replica1/] nUpdates=100
[junit4:junit4] 2> 663009 T862 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica2 url=http://127.0.0.1:49408/hm_dlx/z DONE. We have no versions. sync failed.
[junit4:junit4] 2> 663010 T862 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4] 2> 663011 T862 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> 663011 T862 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49408/hm_dlx/z/nodes_used_collection_shard1_replica2/
[junit4:junit4] 2> 663012 T862 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leaders/shard1
[junit4:junit4] 2> ASYNC NEW_CORE C327 name=nodes_used_collection_shard1_replica1 org.apache.solr.core.SolrCore@150511ef url=http://127.0.0.1:49399/hm_dlx/z/nodes_used_collection_shard1_replica1 node=127.0.0.1:49399_hm_dlx%2Fz C327_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:49399_hm_dlx%2Fz, base_url=http://127.0.0.1:49399/hm_dlx/z}
[junit4:junit4] 2> 663031 T819 C327 P49399 oasc.SolrCore.execute [nodes_used_collection_shard1_replica1] webapp=/hm_dlx/z path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=4
[junit4:junit4] 2> 663040 T846 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 663041 T846 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 663041 T846 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49405/hm_dlx/z/nodes_used_collection_shard2_replica2/
[junit4:junit4] 2> 663042 T846 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica2 url=http://127.0.0.1:49405/hm_dlx/z START replicas=[http://127.0.0.1:49395/hm_dlx/z/nodes_used_collection_shard2_replica1/] nUpdates=100
[junit4:junit4] 2> 663043 T846 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica2 url=http://127.0.0.1:49405/hm_dlx/z DONE. We have no versions. sync failed.
[junit4:junit4] 2> 663043 T846 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4] 2> 663044 T846 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> 663044 T846 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49405/hm_dlx/z/nodes_used_collection_shard2_replica2/
[junit4:junit4] 2> 663045 T846 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leaders/shard2
[junit4:junit4] 2> ASYNC NEW_CORE C328 name=nodes_used_collection_shard2_replica1 org.apache.solr.core.SolrCore@43f420ba url=http://127.0.0.1:49395/hm_dlx/z/nodes_used_collection_shard2_replica1 node=127.0.0.1:49395_hm_dlx%2Fz C328_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:49395_hm_dlx%2Fz, base_url=http://127.0.0.1:49395/hm_dlx/z}
[junit4:junit4] 2> 663077 T803 C328 P49395 oasc.SolrCore.execute [nodes_used_collection_shard2_replica1] webapp=/hm_dlx/z path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4:junit4] 2> 664290 T808 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 664317 T807 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> 664318 T825 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> 664318 T867 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> 664321 T839 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> 664329 T853 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> 664329 T812 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> 664358 T818 oasc.ZkController.register We are http://127.0.0.1:49399/hm_dlx/z/nodes_used_collection_shard1_replica1/ and leader is http://127.0.0.1:49408/hm_dlx/z/nodes_used_collection_shard1_replica2/
[junit4:junit4] 2> 664358 T818 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard1_replica1 baseURL=http://127.0.0.1:49399/hm_dlx/z
[junit4:junit4] 2> 664359 T818 oasc.ZkController.checkRecovery Core needs to recover:nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 664359 T818 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> 664361 T879 C327 P49399 oasc.RecoveryStrategy.run Starting recovery process. core=nodes_used_collection_shard1_replica1 recoveringAfterStartup=true
[junit4:junit4] 2> 664361 T879 C327 P49399 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 664362 T879 C327 P49399 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=recovering
[junit4:junit4] 2> 664365 T818 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 664369 T818 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=8064
[junit4:junit4] 2> 664371 T879 C327 P49399 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 664381 T846 oasc.ZkController.register We are http://127.0.0.1:49405/hm_dlx/z/nodes_used_collection_shard2_replica2/ and leader is http://127.0.0.1:49405/hm_dlx/z/nodes_used_collection_shard2_replica2/
[junit4:junit4] 2> 664382 T846 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard2_replica2 baseURL=http://127.0.0.1:49405/hm_dlx/z
[junit4:junit4] 2> 664382 T846 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 664383 T846 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica2 state=active
[junit4:junit4] 2> 664384 T862 oasc.ZkController.register We are http://127.0.0.1:49408/hm_dlx/z/nodes_used_collection_shard1_replica2/ and leader is http://127.0.0.1:49408/hm_dlx/z/nodes_used_collection_shard1_replica2/
[junit4:junit4] 2> 664385 T862 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard1_replica2 baseURL=http://127.0.0.1:49408/hm_dlx/z
[junit4:junit4] 2> 664385 T862 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 664386 T862 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica2 state=active
[junit4:junit4] 2> 664386 T802 oasc.ZkController.register We are http://127.0.0.1:49395/hm_dlx/z/nodes_used_collection_shard2_replica1/ and leader is http://127.0.0.1:49405/hm_dlx/z/nodes_used_collection_shard2_replica2/
[junit4:junit4] 2> 664387 T802 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard2_replica1 baseURL=http://127.0.0.1:49395/hm_dlx/z
[junit4:junit4] 2> 664387 T802 oasc.ZkController.checkRecovery Core needs to recover:nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 664388 T802 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> 664392 T880 C328 P49395 oasc.RecoveryStrategy.run Starting recovery process. core=nodes_used_collection_shard2_replica1 recoveringAfterStartup=true
[junit4:junit4] 2> 664393 T880 C328 P49395 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 664398 T880 C328 P49395 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica1 state=recovering
[junit4:junit4] 2> 664402 T802 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 664403 T880 C328 P49395 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 664409 T862 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 664411 T802 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=8105
[junit4:junit4] 2> 664427 T846 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 664431 T846 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=8123
[junit4:junit4] 2> 664432 T862 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=8127
[junit4:junit4] 2> 664439 T809 oasc.OverseerCollectionProcessor.createCollection Finished create command on all shards for collection: nodes_used_collection
[junit4:junit4] 2> 664500 T863 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:49399_hm_dlx%2Fz_nodes_used_collection_shard1_replica1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 664509 T848 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:49395_hm_dlx%2Fz_nodes_used_collection_shard2_replica1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 664510 T825 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work/qnr-0000000000 state: SyncConnected type NodeDataChanged
[junit4:junit4] 2> 664519 T807 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 664523 T809 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Message id:/overseer/collection-queue-work/qn-0000000000 complete, response:{success={null={responseHeader={status=0,QTime=8064},core=nodes_used_collection_shard1_replica1},null={responseHeader={status=0,QTime=8105},core=nodes_used_collection_shard2_replica1},null={responseHeader={status=0,QTime=8123},core=nodes_used_collection_shard2_replica2},null={responseHeader={status=0,QTime=8127},core=nodes_used_collection_shard1_replica2}}}
[junit4:junit4] 2> 664523 T817 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=8251
[junit4:junit4] 2> 664525 T785 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 664531 T785 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 664537 T882 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@158bb81c name:ZooKeeperConnection Watcher:127.0.0.1:49392/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 664537 T785 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 664542 T785 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 664551 T785 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 664556 T785 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 664561 T884 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4c23c135 name:ZooKeeperConnection Watcher:127.0.0.1:49392/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 664561 T785 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 664565 T785 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 664631 T819 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=5&maxShardsPerNode=6&name=awholynewcollection_0&replicationFactor=5&action=CREATE&wt=javabin&version=2
[junit4:junit4] 2> 664636 T807 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 664640 T809 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":"5",
[junit4:junit4] 2> "maxShardsPerNode":"6",
[junit4:junit4] 2> "createNodeSet":null,
[junit4:junit4] 2> "name":"awholynewcollection_0",
[junit4:junit4] 2> "replicationFactor":"5"}
[junit4:junit4] 2> 664640 T809 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica1 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:49402_hm_dlx%2Fz
[junit4:junit4] 2> 664641 T809 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica2 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:49395_hm_dlx%2Fz
[junit4:junit4] 2> 664641 T809 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica3 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:49408_hm_dlx%2Fz
[junit4:junit4] 2> 664641 T809 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica4 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:49399_hm_dlx%2Fz
[junit4:junit4] 2> 664641 T809 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica5 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:49405_hm_dlx%2Fz
[junit4:junit4] 2> 664642 T809 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica1 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:49402_hm_dlx%2Fz
[junit4:junit4] 2> 664644 T809 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica2 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:49395_hm_dlx%2Fz
[junit4:junit4] 2> 664647 T809 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica3 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:49408_hm_dlx%2Fz
[junit4:junit4] 2> 664652 T835 oasc.ZkController.publish publishing core=awholynewcollection_0_shard2_replica1 state=down
[junit4:junit4] 2> 664664 T849 oasc.ZkController.publish publishing core=awholynewcollection_0_shard1_replica5 state=down
[junit4:junit4] 2> 664653 T809 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica4 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:49399_hm_dlx%2Fz
[junit4:junit4] 2> 664672 T830 oasc.ZkController.publish publishing core=awholynewcollection_0_shard1_replica1 state=down
[junit4:junit4] 2> 664671 T859 oasc.ZkController.publish publishing core=awholynewcollection_0_shard2_replica3 state=down
[junit4:junit4] 2> 664670 T820 oasc.ZkController.publish publishing core=awholynewcollection_0_shard1_replica4 state=down
[junit4:junit4] 2> 664667 T858 oasc.ZkController.publish publishing core=awholynewcollection_0_shard1_replica3 state=down
[junit4:junit4] 2> 664667 T803 oasc.ZkController.publish publishing core=awholynewcollection_0_shard2_replica2 state=down
[junit4:junit4] 2> 664666 T801 oasc.ZkController.publish publishing core=awholynewcollection_0_shard1_replica2 state=down
[junit4:junit4] 2> 664676 T816 oasc.ZkController.publish publishing core=awholynewcollection_0_shard2_replica4 state=down
[junit4:junit4] 2> 664675 T809 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica5 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:49405_hm_dlx%2Fz
[junit4:junit4] 2> 664684 T809 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard3_replica1 as part of slice shard3 of collection awholynewcollection_0 on 127.0.0.1:49402_hm_dlx%2Fz
[junit4:junit4] 2> 664687 T844 oasc.ZkController.publish publishing core=awholynewcollection_0_shard2_replica5 state=down
[junit4:junit4] 2> 664689 T809 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard3_replica2 as part of slice shard3 of collection awholynewcollection_0 on 127.0.0.1:49395_hm_dlx%2Fz
[junit4:junit4] 2> 664691 T831 oasc.ZkController.publish publishing core=awholynewcollection_0_shard3_replica1 state=down
[junit4:junit4] 2> 664695 T798 oasc.ZkController.publish publishing core=awholynewcollection_0_shard3_replica2 state=down
[junit4:junit4] 2> 664695 T809 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard3_replica3 as part of slice shard3 of collection awholynewcollection_0 on 127.0.0.1:49408_hm_dlx%2Fz
[junit4:junit4] 2> 664705 T809 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard3_replica4 as part of slice shard3 of collection awholynewcollection_0 on 127.0.0.1:49399_hm_dlx%2Fz
[junit4:junit4] 2> 664708 T809 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard3_replica5 as part of slice shard3 of collection awholynewcollection_0 on 127.0.0.1:49405_hm_dlx%2Fz
[junit4:junit4] 2> 664709 T860 oasc.ZkController.publish publishing core=awholynewcollection_0_shard3_replica3 state=down
[junit4:junit4] 2> 664713 T818 oasc.ZkController.publish publishing core=awholynewcollection_0_shard3_replica4 state=down
[junit4:junit4] 2> 664716 T809 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard4_replica1 as part of slice shard4 of collection awholynewcollection_0 on 127.0.0.1:49402_hm_dlx%2Fz
[junit4:junit4] 2> 664719 T845 oasc.ZkController.publish publishing core=awholynewcollection_0_shard3_replica5 state=down
[junit4:junit4] 2> 664722 T809 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard4_replica2 as part of slice shard4 of collection awholynewcollection_0 on 127.0.0.1:49395_hm_dlx%2Fz
[junit4:junit4] 2> 664724 T809 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard4_replica3 as part of slice shard4 of collection awholynewcollection_0 on 127.0.0.1:49408_hm_dlx%2Fz
[junit4:junit4] 2> 664730 T809 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard4_replica4 as part of slice shard4 of collection awholynewcollection_0 on 127.0.0.1:49399_hm_dlx%2Fz
[junit4:junit4] 2> 664730 T832 oasc.ZkController.publish publishing core=awholynewcollection_0_shard4_replica1 state=down
[junit4:junit4] 2> 664741 T861 oasc.ZkController.publish publishing core=awholynewcollection_0_shard4_replica3 state=down
[junit4:junit4] 2> 664733 T809 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard4_replica5 as part of slice shard4 of collection awholynewcollection_0 on 127.0.0.1:49405_hm_dlx%2Fz
[junit4:junit4] 2> 664730 T800 oasc.ZkController.publish publishing core=awholynewcollection_0_shard4_replica2 state=down
[junit4:junit4] 2> 664745 T809 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard5_replica1 as part of slice shard5 of collection awholynewcollection_0 on 127.0.0.1:49402_hm_dlx%2Fz
[junit4:junit4] 2> 664750 T817 oasc.ZkController.publish publishing core=awholynewcollection_0_shard4_replica4 state=down
[junit4:junit4] 2> 664750 T846 oasc.ZkController.publish publishing core=awholynewcollection_0_shard4_replica5 state=down
[junit4:junit4] 2> 664757 T833 oasc.ZkController.publish publishing core=awholynewcollection_0_shard5_replica1 state=down
[junit4:junit4] 2> 664753 T809 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard5_replica2 as part of slice shard5 of collection awholynewcollection_0 on 127.0.0.1:49395_hm_dlx%2Fz
[junit4:junit4] 2> 664760 T809 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard5_replica3 as part of slice shard5 of collection awholynewcollection_0 on 127.0.0.1:49408_hm_dlx%2Fz
[junit4:junit4] 2> 664764 T809 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard5_replica4 as part of slice shard5 of collection awholynewcollection_0 on 127.0.0.1:49399_hm_dlx%2Fz
[junit4:junit4] 2> 664765 T802 oasc.ZkController.publish publishing core=awholynewcollection_0_shard5_replica2 state=down
[junit4:junit4] 2> 664767 T862 oasc.ZkController.publish publishing core=awholynewcollection_0_shard5_replica3 state=down
[junit4:junit4] 2> 664769 T809 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard5_replica5 as part of slice shard5 of collection awholynewcollection_0 on 127.0.0.1:49405_hm_dlx%2Fz
[junit4:junit4] 2> 664773 T815 oasc.ZkController.publish publishing core=awholynewcollection_0_shard5_replica4 state=down
[junit4:junit4] 2> 664777 T847 oasc.ZkController.publish publishing core=awholynewcollection_0_shard5_replica5 state=down
[junit4:junit4] 2> 665860 T808 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 665862 T808 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:49399_hm_dlx%2Fz_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:49399_hm_dlx%2Fz",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49399/hm_dlx/z"}
[junit4:junit4] 2> 665878 T808 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:49408_hm_dlx%2Fz_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:49408_hm_dlx%2Fz",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49408/hm_dlx/z"}
[junit4:junit4] 2> 665893 T808 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:49405_hm_dlx%2Fz_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:49405_hm_dlx%2Fz",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49405/hm_dlx/z"}
[junit4:junit4] 2> 665904 T808 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:49395_hm_dlx%2Fz_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:49395_hm_dlx%2Fz",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49395/hm_dlx/z"}
[junit4:junit4] 2> 665916 T808 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[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":"awholynewcollection_0_shard2_replica1",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:49402_hm_dlx%2Fz",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49402/hm_dlx/z"}
[junit4:junit4] 2> 665916 T808 oasc.Overseer$ClusterStateUpdater.createCollection Create collection awholynewcollection_0 with numShards 5
[junit4:junit4] 2> 665936 T808 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[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":"awholynewcollection_0_shard2_replica3",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:49408_hm_dlx%2Fz",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49408/hm_dlx/z"}
[junit4:junit4] 2> 665948 T808 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[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:49402_hm_dlx%2Fz",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49402/hm_dlx/z"}
[junit4:junit4] 2> 665961 T808 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[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:49399_hm_dlx%2Fz",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49399/hm_dlx/z"}
[junit4:junit4] 2> 665973 T808 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[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_replica5",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:49405_hm_dlx%2Fz",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49405/hm_dlx/z"}
[junit4:junit4] 2> 665989 T808 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[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":"awholynewcollection_0_shard2_replica4",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:49399_hm_dlx%2Fz",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49399/hm_dlx/z"}
[junit4:junit4] 2> 666005 T808 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[junit4:junit4] 2> "shard":"shard3",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"awholynewcollection_0_shard3_replica1",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:49402_hm_dlx%2Fz",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49402/hm_dlx/z"}
[junit4:junit4] 2> 666021 T808 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[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":"awholynewcollection_0_shard2_replica2",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:49395_hm_dlx%2Fz",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49395/hm_dlx/z"}
[junit4:junit4] 2> 666034 T808 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[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":"awholynewcollection_0_shard2_replica5",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:49405_hm_dlx%2Fz",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49405/hm_dlx/z"}
[junit4:junit4] 2> 666047 T808 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[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:49408_hm_dlx%2Fz",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49408/hm_dlx/z"}
[junit4:junit4] 2> 666058 T808 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[junit4:junit4] 2> "shard":"shard3",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"awholynewcollection_0_shard3_replica3",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:49408_hm_dlx%2Fz",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49408/hm_dlx/z"}
[junit4:junit4] 2> 666078 T808 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[junit4:junit4] 2> "shard":"shard3",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"awholynewcollection_0_shard3_replica4",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:49399_hm_dlx%2Fz",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49399/hm_dlx/z"}
[junit4:junit4] 2> 666091 T808 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[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:49395_hm_dlx%2Fz",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49395/hm_dlx/z"}
[junit4:junit4] 2> 666104 T808 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[junit4:junit4] 2> "shard":"shard3",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"awholynewcollection_0_shard3_replica2",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:49395_hm_dlx%2Fz",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49395/hm_dlx/z"}
[junit4:junit4] 2> 666115 T808 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[junit4:junit4] 2> "shard":"shard3",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"awholynewcollection_0_shard3_replica5",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:49405_hm_dlx%2Fz",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49405/hm_dlx/z"}
[junit4:junit4] 2> 666131 T808 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[junit4:junit4] 2> "shard":"shard4",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"awholynewcollection_0_shard4_replica1",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:49402_hm_dlx%2Fz",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49402/hm_dlx/z"}
[junit4:junit4] 2> 666147 T808 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[junit4:junit4] 2> "shard":"shard4",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"awholynewcollection_0_shard4_replica2",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:49395_hm_dlx%2Fz",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49395/hm_dlx/z"}
[junit4:junit4] 2> 666173 T808 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[junit4:junit4] 2> "shard":"shard4",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"awholynewcollection_0_shard4_replica3",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:49408_hm_dlx%2Fz",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49408/hm_dlx/z"}
[junit4:junit4] 2> 666185 T808 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[junit4:junit4] 2> "shard":"shard4",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"awholynewcollection_0_shard4_replica4",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:49399_hm_dlx%2Fz",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49399/hm_dlx/z"}
[junit4:junit4] 2> 666200 T808 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[junit4:junit4] 2> "shard":"shard4",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"awholynewcollection_0_shard4_replica5",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:49405_hm_dlx%2Fz",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49405/hm_dlx/z"}
[junit4:junit4] 2> 666214 T808 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[junit4:junit4] 2> "shard":"shard5",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"awholynewcollection_0_shard5_replica1",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:49402_hm_dlx%2Fz",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49402/hm_dlx/z"}
[junit4:junit4] 2> 666226 T808 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[junit4:junit4] 2> "shard":"shard5",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"awholynewcollection_0_shard5_replica3",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:49408_hm_dlx%2Fz",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49408/hm_dlx/z"}
[junit4:junit4] 2> 666242 T808 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[junit4:junit4] 2> "shard":"shard5",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"awholynewcollection_0_shard5_replica4",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:49399_hm_dlx%2Fz",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49399/hm_dlx/z"}
[junit4:junit4] 2> 666253 T808 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[junit4:junit4] 2> "shard":"shard5",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"awholynewcollection_0_shard5_replica2",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:49395_hm_dlx%2Fz",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49395/hm_dlx/z"}
[junit4:junit4] 2> 666271 T808 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=5 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"5",
[junit4:junit4] 2> "shard":"shard5",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"awholynewcollection_0_shard5_replica5",
[junit4:junit4] 2> "collection":"awholynewcollection_0",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:49405_hm_dlx%2Fz",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49405/hm_dlx/z"}
[junit4:junit4] 2> 666284 T839 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> 666285 T853 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> 666285 T884 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> 666285 T867 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> 666285 T825 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> 666285 T882 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> 666285 T812 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> 666305 T807 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> 666503 T863 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:49399_hm_dlx%2Fz_nodes_used_collection_shard1_replica1, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 666506 T863 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:49399_hm_dlx%252Fz_nodes_used_collection_shard1_replica1&state=recovering&nodeName=127.0.0.1:49399_hm_dlx%252Fz&action=PREPRECOVERY&checkLive=true&core=nodes_used_collection_shard1_replica2&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2006
[junit4:junit4] 2> 666512 T848 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:49395_hm_dlx%2Fz_nodes_used_collection_shard2_replica1, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 666512 T848 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:49395_hm_dlx%252Fz_nodes_used_collection_shard2_replica1&state=recovering&nodeName=127.0.0.1:49395_hm_dlx%252Fz&action=PREPRECOVERY&checkLive=true&core=nodes_used_collection_shard2_replica2&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2003
[junit4:junit4] 2> 666684 T835 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1371714259723/awholynewcollection_0_shard2_replica1
[junit4:junit4] 2> 666685 T835 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 666687 T835 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 666687 T835 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 666691 T835 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 666691 T835 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 666701 T859 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica3' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1371714264161/awholynewcollection_0_shard2_replica3
[junit4:junit4] 2> 666702 T859 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 666701 T830 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-1371714259723/awholynewcollection_0_shard1_replica1
[junit4:junit4] 2> 666703 T830 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 666703 T849 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard1_replica5' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371714261887/awholynewcollection_0_shard1_replica5
[junit4:junit4] 2> 666705 T849 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 666705 T859 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 666706 T859 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 666702 T820 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-1371714257544/awholynewcollection_0_shard1_replica4
[junit4:junit4] 2> 666707 T820 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 666707 T830 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 666709 T830 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 666706 T835 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 666711 T849 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 666712 T849 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 666717 T820 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 666718 T820 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 666717 T859 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-1371714264161/awholynewcollection_0_shard2_replica3/'
[junit4:junit4] 2> 666728 T816 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica4' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371714257544/awholynewcollection_0_shard2_replica4
[junit4:junit4] 2> 666729 T816 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 666731 T830 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-1371714259723/awholynewcollection_0_shard1_replica1/'
[junit4:junit4] 2> 666731 T831 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard3_replica1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1371714259723/awholynewcollection_0_shard3_replica1
[junit4:junit4] 2> 666742 T831 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 666754 T818 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard3_replica4' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371714257544/awholynewcollection_0_shard3_replica4
[junit4:junit4] 2> 666754 T818 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 666763 T832 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard4_replica1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1371714259723/awholynewcollection_0_shard4_replica1
[junit4:junit4] 2> 666764 T832 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 666765 T860 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard3_replica3' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1371714264161/awholynewcollection_0_shard3_replica3
[junit4:junit4] 2> 666769 T860 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 666767 T861 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard4_replica3' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1371714264161/awholynewcollection_0_shard4_replica3
[junit4:junit4] 2> 666771 T861 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 666772 T798 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard3_replica2' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1371714256139/awholynewcollection_0_shard3_replica2
[junit4:junit4] 2> 666772 T798 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 666769 T800 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard4_replica2' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1371714256139/awholynewcollection_0_shard4_replica2
[junit4:junit4] 2> 666773 T800 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 666768 T835 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-1371714259723/awholynewcollection_0_shard2_replica1/'
[junit4:junit4] 2> 666782 T846 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard4_replica5' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371714261887/awholynewcollection_0_shard4_replica5
[junit4:junit4] 2> 666783 T846 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 666783 T845 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard3_replica5' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371714261887/awholynewcollection_0_shard3_replica5
[junit4:junit4] 2> 666784 T845 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 666784 T817 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard4_replica4' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371714257544/awholynewcollection_0_shard4_replica4
[junit4:junit4] 2> 666785 T817 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 666786 T802 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard5_replica2' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1371714256139/awholynewcollection_0_shard5_replica2
[junit4:junit4] 2> 666786 T802 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 666785 T833 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard5_replica1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1371714259723/awholynewcollection_0_shard5_replica1
[junit4:junit4] 2> 666787 T833 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 666791 T801 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-1371714256139/awholynewcollection_0_shard1_replica2
[junit4:junit4] 2> 666792 T801 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 666793 T847 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard5_replica5' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371714261887/awholynewcollection_0_shard5_replica5
[junit4:junit4] 2> 666793 T847 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 666788 T815 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard5_replica4' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1371714257544/awholynewcollection_0_shard5_replica4
[junit4:junit4] 2> 666794 T815 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 666788 T862 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard5_replica3' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1371714264161/awholynewcollection_0_shard5_replica3
[junit4:junit4] 2> 666795 T862 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 666796 T803 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica2' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1371714256139/awholynewcollection_0_shard2_replica2
[junit4:junit4] 2> 666796 T803 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 666798 T858 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-jetty4-1371714264161/awholynewcollection_0_shard1_replica3
[junit4:junit4] 2> 666798 T858 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 666799 T844 oasc.CoreContainer.create Creating SolrCore 'awholynewcollection_0_shard2_replica5' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1371714261887/awholynewcollection_0_shard2_replica5
[junit4:junit4] 2> 666799 T844 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 666820 T816 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 666821 T816 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 666824 T849 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-1371714261887/awholynewcollection_0_shard1_replica5/'
[junit4:junit4] 2> 666826 T818 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 666826 T818 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 666827 T815 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 666828 T815 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 666829 T846 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 666829 T846 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 666830 T847 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 666830 T847 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 666833 T817 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 666833 T817 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 666833 T861 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 666835 T861 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 666833 T860 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 666836 T860 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 666835 T832 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 666838 T832 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 666835 T831 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 666839 T831 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 666834 T862 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 666840 T862 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 666834 T844 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 666841 T844 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 666834 T845 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 666843 T845 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 666833 T858 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 666844 T858 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 666844 T833 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 666845 T833 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 666839 T798 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 666847 T798 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 666845 T820 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-1371714257544/awholynewcollection_0_shard1_replica4/'
[junit4:junit4] 2> 666859 T846 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-1371714261887/awholynewcollection_0_shard4_replica5/'
[junit4:junit4] 2> 666860 T847 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-1371714261887/awholynewcollection_0_shard5_replica5/'
[junit4:junit4] 2> 666862 T816 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-1371714257544/awholynewcollection_0_shard2_replica4/'
[junit4:junit4] 2> 666865 T800 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 666866 T800 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 666868 T818 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-1371714257544/awholynewcollection_0_shard3_replica4/'
[junit4:junit4] 2> 666869 T815 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-1371714257544/awholynewcollection_0_shard5_replica4/'
[junit4:junit4] 2> 666870 T861 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-1371714264161/awholynewcollection_0_shard4_replica3/'
[junit4:junit4] 2> 666872 T817 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-1371714257544/awholynewcollection_0_shard4_replica4/'
[junit4:junit4] 2> 666874 T802 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 666874 T802 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 666875 T862 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-1371714264161/awholynewcollection_0_shard5_replica3/'
[junit4:junit4] 2> 666876 T860 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-1371714264161/awholynewcollection_0_shard3_replica3/'
[junit4:junit4] 2> 666879 T858 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-1371714264161/awholynewcollection_0_shard1_replica3/'
[junit4:junit4] 2> 666880 T844 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-1371714261887/awholynewcollection_0_shard2_replica5/'
[junit4:junit4] 2> 666881 T845 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-1371714261887/awholynewcollection_0_shard3_replica5/'
[junit4:junit4] 2> 666883 T801 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 666884 T801 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 666887 T832 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-1371714259723/awholynewcollection_0_shard4_replica1/'
[junit4:junit4] 2> 666888 T803 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 666893 T803 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 666895 T831 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-1371714259723/awholynewcollection_0_shard3_replica1/'
[junit4:junit4] 2> 666898 T833 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-1371714259723/awholynewcollection_0_shard5_replica1/'
[junit4:junit4] 2> 666902 T798 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-1371714256139/awholynewcollection_0_shard3_replica2/'
[junit4:junit4] 2> 666904 T800 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-1371714256139/awholynewcollection_0_shard4_replica2/'
[junit4:junit4] 2> 666907 T802 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-1371714256139/awholynewcollection_0_shard5_replica2/'
[junit4:junit4] 2> 666983 T801 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-1371714256139/awholynewcollection_0_shard1_replica2/'
[junit4:junit4] 2> 666994 T803 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-1371714256139/awholynewcollection_0_shard2_replica2/'
[junit4:junit4] 2> 667816 T847 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 667827 T835 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 667876 T862 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 667884 T830 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 667920 T859 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 668016 T860 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 668077 T849 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 668127 T802 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 668401 T816 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 668420 T831 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 668429 T815 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 668478 T818 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 668491 T801 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> ASYNC NEW_CORE C329 name=nodes_used_collection_shard1_replica1 org.apache.solr.core.SolrCore@150511ef url=http://127.0.0.1:49399/hm_dlx/z/nodes_used_collection_shard1_replica1 node=127.0.0.1:49399_hm_dlx%2Fz C329_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:49399_hm_dlx%2Fz, base_url=http://127.0.0.1:49399/hm_dlx/z}
[junit4:junit4] 2> 668509 T879 C329 P49399 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:49408/hm_dlx/z/nodes_used_collection_shard1_replica2/ core=nodes_used_collection_shard1_replica1 - recoveringAfterStartup=true
[junit4:junit4] 2> 668509 T879 C329 P49399 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica1 url=http://127.0.0.1:49399/hm_dlx/z START replicas=[http://127.0.0.1:49408/hm_dlx/z/nodes_used_collection_shard1_replica2/] nUpdates=100
[junit4:junit4] 2> 668510 T879 C329 P49399 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 668510 T879 C329 P49399 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 668511 T879 C329 P49399 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 668511 T879 C329 P49399 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 668511 T879 C329 P49399 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 668511 T879 C329 P49399 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:49408/hm_dlx/z/nodes_used_collection_shard1_replica2/. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 668512 T879 C329 P49399 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C330 name=nodes_used_collection_shard2_replica1 org.apache.solr.core.SolrCore@43f420ba url=http://127.0.0.1:49395/hm_dlx/z/nodes_used_collection_shard2_replica1 node=127.0.0.1:49395_hm_dlx%2Fz C330_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:49395_hm_dlx%2Fz, base_url=http://127.0.0.1:49395/hm_dlx/z}
[junit4:junit4] 2> 668515 T880 C330 P49395 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:49405/hm_dlx/z/nodes_used_collection_shard2_replica2/ core=nodes_used_collection_shard2_replica1 - recoveringAfterStartup=true
[junit4:junit4] 2> 668515 T880 C330 P49395 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica1 url=http://127.0.0.1:49395/hm_dlx/z START replicas=[http://127.0.0.1:49405/hm_dlx/z/nodes_used_collection_shard2_replica2/] nUpdates=100
[junit4:junit4] 2> 668522 T880 C330 P49395 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 668525 T880 C330 P49395 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 668525 T880 C330 P49395 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 668525 T880 C330 P49395 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 668526 T880 C330 P49395 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 668526 T880 C330 P49395 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:49405/hm_dlx/z/nodes_used_collection_shard2_replica2/. core=nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 668526 T880 C330 P49395 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C331 name=nodes_used_collection_shard1_replica2 org.apache.solr.core.SolrCore@1ac7e25d url=http://127.0.0.1:49408/hm_dlx/z/nodes_used_collection_shard1_replica2 node=127.0.0.1:49408_hm_dlx%2Fz C331_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:49408_hm_dlx%2Fz, base_url=http://127.0.0.1:49408/hm_dlx/z, leader=true}
[junit4:junit4] 2> 668558 T863 C331 P49408 oasc.SolrCore.execute [nodes_used_collection_shard1_replica2] webapp=/hm_dlx/z path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=14
[junit4:junit4] 2> 668561 T909 C331 P49408 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 668616 T846 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 668622 T858 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 668635 T803 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 668651 T861 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> ASYNC NEW_CORE C332 name=nodes_used_collection_shard1_replica2 org.apache.solr.core.SolrCore@1ac7e25d url=http://127.0.0.1:49408/hm_dlx/z/nodes_used_collection_shard1_replica2 node=127.0.0.1:49408_hm_dlx%2Fz C332_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:49408_hm_dlx%2Fz, base_url=http://127.0.0.1:49408/hm_dlx/z, leader=true}
[junit4:junit4] 2> 668814 T909 C332 P49408 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6058de27 lockFactory=org.apache.lucene.store.NativeFSLockFactory@17446ad5),segFN=segments_1,generation=1}
[junit4:junit4] 2> 668815 T909 C332 P49408 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 668855 T909 C332 P49408 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6058de27 lockFactory=org.apache.lucene.store.NativeFSLockFactory@17446ad5),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6058de27 lockFactory=org.apache.lucene.store.NativeFSLockFactory@17446ad5),segFN=segments_2,generation=2}
[junit4:junit4] 2> 668857 T909 C332 P49408 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> ASYNC NEW_CORE C333 name=nodes_used_collection_shard2_replica2 org.apache.solr.core.SolrCore@9d5de9 url=http://127.0.0.1:49405/hm_dlx/z/nodes_used_collection_shard2_replica2 node=127.0.0.1:49405_hm_dlx%2Fz C333_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:49405_hm_dlx%2Fz, base_url=http://127.0.0.1:49405/hm_dlx/z, leader=true}
[junit4:junit4] 2> 668869 T911 C333 P49405 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 668889 T909 C332 P49408 oass.SolrIndexSearcher.<init> Opening Searcher@7ffca5b8 realtime
[junit4:junit4] 2> 668890 T909 C332 P49408 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 668891 T909 C332 P49408 oasup.LogUpdateProcessor.finish [nodes_used_collection_shard1_replica2] webapp=/hm_dlx/z path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 330
[junit4:junit4] 2> ASYNC NEW_CORE C334 name=nodes_used_collection_shard1_replica1 org.apache.solr.core.SolrCore@150511ef url=http://127.0.0.1:49399/hm_dlx/z/nodes_used_collection_shard1_replica1 node=127.0.0.1:49399_hm_dlx%2Fz C334_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:49399_hm_dlx%2Fz, base_url=http://127.0.0.1:49399/hm_dlx/z}
[junit4:junit4] 2> 668894 T879 C334 P49399 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 668894 T879 C334 P49399 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 668909 T833 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 668915 T844 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 668919 T800 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 668920 T909 C332 P49408 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 668920 T909 C332 P49408 oasc.SolrCore.execute [nodes_used_collection_shard1_replica2] webapp=/hm_dlx/z path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=2
[junit4:junit4] 2> 668970 T820 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 668981 T879 C334 P49399 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 668982 T879 C334 P49399 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 668983 T879 C334 P49399 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 669006 T863 C332 P49408 oasc.SolrCore.execute [nodes_used_collection_shard1_replica2] webapp=/hm_dlx/z path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=11
[junit4:junit4] 2> 669009 T879 C334 P49399 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 669044 T879 C334 P49399 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-1371714257544/nodes_used_collection_shard1_replica1/data/index.20130620094439081
[junit4:junit4] 2> 669081 T879 C334 P49399 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@66cfeead lockFactory=org.apache.lucene.store.NativeFSLockFactory@25f807c4) fullCopy=false
[junit4:junit4] 2> 669095 T911 C333 P49405 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2c823d00 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1da3fa09),segFN=segments_1,generation=1}
[junit4:junit4] 2> 669106 T911 C333 P49405 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 669108 T909 C332 P49408 oasc.SolrCore.execute [nodes_used_collection_shard1_replica2] webapp=/hm_dlx/z path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 669115 T832 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 669118 T817 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 669126 T911 C333 P49405 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2c823d00 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1da3fa09),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2c823d00 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1da3fa09),segFN=segments_2,generation=2}
[junit4:junit4] 2> 669127 T911 C333 P49405 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 669128 T911 C333 P49405 oass.SolrIndexSearcher.<init> Opening Searcher@1bd54242 realtime
[junit4:junit4] 2> 669129 T911 C333 P49405 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 669129 T911 C333 P49405 oasup.LogUpdateProcessor.finish [nodes_used_collection_shard2_replica2] webapp=/hm_dlx/z path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 261
[junit4:junit4] 2> ASYNC NEW_CORE C335 name=nodes_used_collection_shard2_replica1 org.apache.solr.core.SolrCore@43f420ba url=http://127.0.0.1:49395/hm_dlx/z/nodes_used_collection_shard2_replica1 node=127.0.0.1:49395_hm_dlx%2Fz C335_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:49395_hm_dlx%2Fz, base_url=http://127.0.0.1:49395/hm_dlx/z}
[junit4:junit4] 2> 669142 T880 C335 P49395 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 669143 T880 C335 P49395 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 669158 T848 C333 P49405 oasc.SolrCore.execute [nodes_used_collection_shard2_replica2] webapp=/hm_dlx/z path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 669175 T879 C334 P49399 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 669177 T848 C333 P49405 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 669177 T848 C333 P49405 oasc.SolrCore.execute [nodes_used_collection_shard2_replica2] webapp=/hm_dlx/z path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=4
[junit4:junit4] 2> 669179 T880 C335 P49395 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 669179 T880 C335 P49395 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 669179 T880 C335 P49395 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 669203 T914 C333 P49405 oasc.SolrCore.execute [nodes_used_collection_shard2_replica2] webapp=/hm_dlx/z path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=10
[junit4:junit4] 2> 669206 T880 C335 P49395 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 669214 T879 C334 P49399 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 669215 T879 C334 P49399 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 669216 T880 C335 P49395 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-1371714256139/nodes_used_collection_shard2_replica1/data/index.20130620094439278
[junit4:junit4] 2> 669217 T880 C335 P49395 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@4456d453 lockFactory=org.apache.lucene.store.NativeFSLockFactory@5f39ee05) fullCopy=false
[junit4:junit4] 2> 669227 T879 C334 P49399 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@516fc4ce lockFactory=org.apache.lucene.store.NativeFSLockFactory@4cc2e9fc),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@516fc4ce lockFactory=org.apache.lucene.store.NativeFSLockFactory@4cc2e9fc),segFN=segments_2,generation=2}
[junit4:junit4] 2> 669227 T879 C334 P49399 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 669228 T879 C334 P49399 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 669229 T879 C334 P49399 oass.SolrIndexSearcher.<init> Opening Searcher@6c4b0d5d main
[junit4:junit4] 2> 669231 T876 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica1] Registered new searcher Searcher@6c4b0d5d main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 669233 T879 C334 P49399 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-1371714257544/nodes_used_collection_shard1_replica1/data/index.20130620094439081 [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-1371714257544/nodes_used_collection_shard1_replica1/data/index.20130620094439081;done=true>>]
[junit4:junit4] 2> 669233 T879 C334 P49399 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-1371714257544/nodes_used_collection_shard1_replica1/data/index.20130620094439081
[junit4:junit4] 2> 669241 T845 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 669249 T879 C334 P49399 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-1371714257544/nodes_used_collection_shard1_replica1/data/index.20130620094439081
[junit4:junit4] 2> 669250 T879 C334 P49399 oasc.RecoveryStrategy.replay No replay needed. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 669250 T879 C334 P49399 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 669250 T879 C334 P49399 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=active
[junit4:junit4] 2> 669255 T879 C334 P49399 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 669260 T911 C333 P49405 oasc.SolrCore.execute [nodes_used_collection_shard2_replica2] webapp=/hm_dlx/z path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 669278 T880 C335 P49395 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 669282 T880 C335 P49395 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 669282 T880 C335 P49395 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=nodes_used_collection_shard2_replica1
[junit4:ju
[...truncated too long message...]
:"collection1",
[junit4:junit4] 1> "collection":"collection1",
[junit4:junit4] 1> "node_name":"127.0.0.1:49532_xm_bai%2Fy",
[junit4:junit4] 1> "base_url":"http://127.0.0.1:49532/xm_bai/y"},
[junit4:junit4] 1> "5":{
[junit4:junit4] 1> "shard":"shard1",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "core":"collection1",
[junit4:junit4] 1> "collection":"collection1",
[junit4:junit4] 1> "node_name":"127.0.0.1:49539_xm_bai%2Fy",
[junit4:junit4] 1> "base_url":"http://127.0.0.1:49539/xm_bai/y",
[junit4:junit4] 1> "leader":"true"}}}},
[junit4:junit4] 1> "router":"compositeId"},
[junit4:junit4] 1> "control_collection":{
[junit4:junit4] 1> "shards":{"shard1":{
[junit4:junit4] 1> "range":"80000000-7fffffff",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "replicas":{"1":{
[junit4:junit4] 1> "shard":"shard1",
[junit4:junit4] 1> "state":"active",
[junit4:junit4] 1> "core":"collection1",
[junit4:junit4] 1> "collection":"control_collection",
[junit4:junit4] 1> "node_name":"127.0.0.1:49521_xm_bai%2Fy",
[junit4:junit4] 1> "base_url":"http://127.0.0.1:49521/xm_bai/y",
[junit4:junit4] 1> "leader":"true"}}}},
[junit4:junit4] 1> "router":"compositeId"}}
[junit4:junit4] 1> /solr/aliases.json (0)
[junit4:junit4] 1> /solr/live_nodes (4)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:49532_xm_bai%2Fy (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:49539_xm_bai%2Fy (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:49521_xm_bai%2Fy (0)
[junit4:junit4] 1> /solr/live_nodes/127.0.0.1:49525_xm_bai%2Fy (0)
[junit4:junit4] 1> /solr/overseer (3)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1>
[junit4:junit4] 1> /solr/overseer/queue (0)
[junit4:junit4] 1> /solr/overseer/queue-work (0)
[junit4:junit4] 1> /solr/overseer/collection-queue-work (0)
[junit4:junit4] 1> /solr/collections (2)
[junit4:junit4] 1> /solr/collections/collection1 (3)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {"configName":"conf1"}
[junit4:junit4] 1> /solr/collections/collection1/shards (0)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect (1)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard1 (1)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard1/election (3)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/89896679124566026-4-n_0000000005 (0)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/89896679124566030-2-n_0000000004 (0)
[junit4:junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/89896679124566028-5-n_0000000003 (0)
[junit4:junit4] 1> /solr/collections/collection1/leaders (1)
[junit4:junit4] 1> /solr/collections/collection1/leaders/shard1 (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "core":"collection1",
[junit4:junit4] 1> "node_name":"127.0.0.1:49539_xm_bai%2Fy",
[junit4:junit4] 1> "base_url":"http://127.0.0.1:49539/xm_bai/y"}
[junit4:junit4] 1> /solr/collections/control_collection (3)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {"configName":"conf1"}
[junit4:junit4] 1> /solr/collections/control_collection/shards (0)
[junit4:junit4] 1> /solr/collections/control_collection/leader_elect (1)
[junit4:junit4] 1> /solr/collections/control_collection/leader_elect/shard1 (1)
[junit4:junit4] 1> /solr/collections/control_collection/leader_elect/shard1/election (1)
[junit4:junit4] 1> /solr/collections/control_collection/leader_elect/shard1/election/89896679124566019-1-n_0000000000 (0)
[junit4:junit4] 1> /solr/collections/control_collection/leaders (1)
[junit4:junit4] 1> /solr/collections/control_collection/leaders/shard1 (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {
[junit4:junit4] 1> "core":"collection1",
[junit4:junit4] 1> "node_name":"127.0.0.1:49521_xm_bai%2Fy",
[junit4:junit4] 1> "base_url":"http://127.0.0.1:49521/xm_bai/y"}
[junit4:junit4] 1> /solr/overseer_elect (2)
[junit4:junit4] 1> /solr/overseer_elect/election (4)
[junit4:junit4] 1> /solr/overseer_elect/election/89896679124566026-127.0.0.1:49532_xm_bai%2Fy-n_0000000003 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89896679124566030-127.0.0.1:49525_xm_bai%2Fy-n_0000000005 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89896679124566028-127.0.0.1:49539_xm_bai%2Fy-n_0000000004 (0)
[junit4:junit4] 1> /solr/overseer_elect/election/89896679124566019-127.0.0.1:49521_xm_bai%2Fy-n_0000000000 (0)
[junit4:junit4] 1> /solr/overseer_elect/leader (0)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1> {"id":"89896679124566019-127.0.0.1:49521_xm_bai%2Fy-n_0000000000"}
[junit4:junit4] 1> /zookeeper (1)
[junit4:junit4] 1> DATA:
[junit4:junit4] 1>
[junit4:junit4] 1>
[junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=SyncSliceTest -Dtests.method=testDistribSearch -Dtests.seed=C44103AB69D2E3 -Dtests.slow=true -Dtests.locale=lt -Dtests.timezone=Australia/Lindeman -Dtests.file.encoding=US-ASCII
[junit4:junit4] FAILURE 140s | SyncSliceTest.testDistribSearch <<<
[junit4:junit4] > Throwable #1: java.lang.AssertionError: shard1 is not consistent. Got 305 from http://127.0.0.1:49525/xm_bai/y/collection1lastClient and got 267 from http://127.0.0.1:49532/xm_bai/y/collection1
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([C44103AB69D2E3:8122CF1BDC36B2DF]:0)
[junit4:junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1018)
[junit4:junit4] > at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:238)
[junit4:junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2> 994489 T1080 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> 140413 T1079 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
[junit4:junit4] 2> NOTE: test params are: codec=Lucene42: {range_facet_l=PostingsFormat(name=Memory doPackFST= true), text=PostingsFormat(name=SimpleText), _version_=PostingsFormat(name=Asserting), rnd_b=Pulsing41(freqCutoff=2 minBlockSize=50 maxBlockSize=160), intDefault=PostingsFormat(name=Asserting), timestamp=PostingsFormat(name=Memory doPackFST= true), id=Pulsing41(freqCutoff=2 minBlockSize=50 maxBlockSize=160), a_t=PostingsFormat(name=Memory doPackFST= true), range_facet_sl=Pulsing41(freqCutoff=2 minBlockSize=50 maxBlockSize=160), range_facet_si=PostingsFormat(name=Memory doPackFST= true), other_tl1=PostingsFormat(name=Asserting), multiDefault=PostingsFormat(name=Memory doPackFST= true), a_si=PostingsFormat(name=Asserting)}, docValues:{timestamp=DocValuesFormat(name=Disk)}, sim=DefaultSimilarity, locale=lt, timezone=Australia/Lindeman
[junit4:junit4] 2> NOTE: Mac OS X 10.8.4 x86_64/Oracle Corporation 1.7.0_21 (64-bit)/cpus=2,threads=1,free=141757232,total=536870912
[junit4:junit4] 2> NOTE: All tests run in this JVM: [TestManagedSchema, TestDocumentBuilder, SystemInfoHandlerTest, PingRequestHandlerTest, TestAddFieldRealTimeGet, UnloadDistributedZkTest, ScriptEngineTest, CopyFieldTest, DOMUtilTest, SolrPluginUtilsTest, TestDefaultSearchFieldResource, TestRealTimeGet, TestFiltering, DateMathParserTest, TestZkChroot, NoCacheHeaderTest, PreAnalyzedFieldTest, TestMaxScoreQueryParser, AliasIntegrationTest, TestCSVLoader, TestGroupingSearch, TestDocSet, URLClassifyProcessorTest, UpdateRequestProcessorFactoryTest, SpellCheckCollatorTest, TestJmxMonitoredMap, TestStressRecovery, DistributedQueryElevationComponentTest, IndexBasedSpellCheckerTest, TestCloudManagedSchema, CollectionsAPIDistributedZkTest, OutputWriterTest, QueryParsingTest, SolrInfoMBeanTest, TestSolrQueryParserResource, TestSolrXMLSerializer, RequestHandlersTest, SyncSliceTest]
[junit4:junit4] Completed in 140.98s, 1 test, 1 failure <<< FAILURES!
[...truncated 805 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: 297 suites, 1252 tests, 1 error, 1 failure, 18 ignored (6 assumptions)
Total time: 110 minutes 5 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure