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/05/28 11:38:41 UTC
[JENKINS] Lucene-Solr-trunk-MacOSX (64bit/jdk1.7.0) - Build # 514 -
Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-MacOSX/514/
Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseParallelGC
2 tests failed.
REGRESSION: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testDistribSearch
Error Message:
There are still nodes recoverying - waited for 230 seconds
Stack Trace:
java.lang.AssertionError: There are still nodes recoverying - waited for 230 seconds
at __randomizedtesting.SeedInfo.seed([BCE488C1890531AE:3D0206D9FE5A5192]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:173)
at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:131)
at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:126)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testCollectionsAPI(CollectionsAPIDistributedZkTest.java:512)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:146)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:815)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:601)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:722)
REGRESSION: org.apache.solr.core.OpenCloseCoreStressTest.test30SecondsNew
Error Message:
Core 00000_core bad! expected:<291> but was:<253>
Stack Trace:
java.lang.AssertionError: Core 00000_core bad! expected:<291> but was:<253>
at __randomizedtesting.SeedInfo.seed([BCE488C1890531AE:D8519415DBC5C8EB]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.apache.solr.core.OpenCloseCoreStressTest.checkResults(OpenCloseCoreStressTest.java:304)
at org.apache.solr.core.OpenCloseCoreStressTest.doStress(OpenCloseCoreStressTest.java:201)
at org.apache.solr.core.OpenCloseCoreStressTest.test30SecondsNew(OpenCloseCoreStressTest.java:121)
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 9554 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4:junit4] 2> 2421218 T3904 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4] 2> 2421226 T3904 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-1369732129032
[junit4:junit4] 2> 2421229 T3904 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 2421230 T3905 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 2421331 T3904 oasc.ZkTestServer.run start zk server on port:50488
[junit4:junit4] 2> 2421333 T3904 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2421341 T3911 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@26594d0b name:ZooKeeperConnection Watcher:127.0.0.1:50488 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2421342 T3904 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2421342 T3904 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 2421359 T3904 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2421361 T3913 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7970f4f5 name:ZooKeeperConnection Watcher:127.0.0.1:50488/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2421361 T3904 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2421361 T3904 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 2421370 T3904 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 2421377 T3904 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 2421391 T3904 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 2421399 T3904 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> 2421400 T3904 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 2421411 T3904 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> 2421412 T3904 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 2421421 T3904 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> 2421423 T3904 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 2421430 T3904 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> 2421431 T3904 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 2421439 T3904 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> 2421440 T3904 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 2421448 T3904 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> 2421448 T3904 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 2421456 T3904 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> 2421458 T3904 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 2421474 T3904 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> 2421475 T3904 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 2421483 T3904 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> 2421484 T3904 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 2422145 T3904 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2422168 T3904 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50491
[junit4:junit4] 2> 2422170 T3904 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2422170 T3904 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2422171 T3904 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-1369732129298
[junit4:junit4] 2> 2422171 T3904 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-1369732129298/solr.xml
[junit4:junit4] 2> 2422172 T3904 oasc.CoreContainer.<init> New CoreContainer 1412670647
[junit4:junit4] 2> 2422173 T3904 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-1369732129298/'
[junit4:junit4] 2> 2422174 T3904 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-1369732129298/'
[junit4:junit4] 2> 2422422 T3904 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-1369732129298
[junit4:junit4] 2> 2422424 T3904 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-1369732129298/collection1
[junit4:junit4] 2> 2422427 T3904 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-1369732129298/collection1/conf
[junit4:junit4] 2> 2422678 T3904 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-1369732129298/collection1/conf/xslt
[junit4:junit4] 2> 2422685 T3904 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-1369732129298/collection1/lib
[junit4:junit4] 2> 2422688 T3904 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-1369732129298/collection1/lib/classes
[junit4:junit4] 2> 2422693 T3904 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-1369732129298/conf/core.properties, adding to cores
[junit4:junit4] 2> 2422728 T3904 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 2422729 T3904 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2422730 T3904 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 2422731 T3904 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2422732 T3904 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2422732 T3904 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2422733 T3904 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2422734 T3904 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2422736 T3904 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2422737 T3904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 2422780 T3904 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2422781 T3904 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50488/solr
[junit4:junit4] 2> 2422782 T3904 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2422784 T3904 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2422794 T3924 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7ff1bcd7 name:ZooKeeperConnection Watcher:127.0.0.1:50488 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2422796 T3904 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2422802 T3904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2422834 T3904 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2422851 T3926 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1232e806 name:ZooKeeperConnection Watcher:127.0.0.1:50488/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2422852 T3904 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2422857 T3904 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 2422870 T3904 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 2422882 T3904 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 2422889 T3904 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50491_
[junit4:junit4] 2> 2422893 T3904 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50491_
[junit4:junit4] 2> 2422904 T3904 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 2422935 T3904 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 2422944 T3904 oasc.Overseer.start Overseer (id=89766764809027587-127.0.0.1:50491_-n_0000000000) starting
[junit4:junit4] 2> 2422955 T3904 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 2422974 T3928 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 2422977 T3904 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 2422983 T3904 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 2422988 T3904 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2423001 T3927 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 2423002 T3904 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 2423003 T3904 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2423004 T3904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2423033 T3904 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 2423038 T3904 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2423043 T3931 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7a62a1bf name:ZooKeeperConnection Watcher:127.0.0.1:50488/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2423044 T3904 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2423048 T3904 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2423056 T3904 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 2423777 T3904 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2423788 T3904 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50495
[junit4:junit4] 2> 2423790 T3904 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2423791 T3904 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2423791 T3904 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-1369732130861
[junit4:junit4] 2> 2423792 T3904 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-1369732130861/solr.xml
[junit4:junit4] 2> 2423793 T3904 oasc.CoreContainer.<init> New CoreContainer 989780260
[junit4:junit4] 2> 2423793 T3904 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-1369732130861/'
[junit4:junit4] 2> 2423794 T3904 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-1369732130861/'
[junit4:junit4] 2> 2423982 T3904 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-1369732130861
[junit4:junit4] 2> 2423984 T3904 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-1369732130861/collection1
[junit4:junit4] 2> 2423985 T3904 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-1369732130861/collection1/conf
[junit4:junit4] 2> 2424169 T3904 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-1369732130861/collection1/conf/xslt
[junit4:junit4] 2> 2424173 T3904 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-1369732130861/collection1/lib
[junit4:junit4] 2> 2424175 T3904 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-1369732130861/collection1/lib/classes
[junit4:junit4] 2> 2424179 T3904 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-1369732130861/conf/core.properties, adding to cores
[junit4:junit4] 2> 2424197 T3904 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 2424197 T3904 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2424198 T3904 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 2424198 T3904 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2424201 T3904 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2424202 T3904 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2424202 T3904 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2424203 T3904 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2424204 T3904 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2424205 T3904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 2424237 T3904 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2424238 T3904 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50488/solr
[junit4:junit4] 2> 2424239 T3904 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2424241 T3904 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2424245 T3942 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5525076f name:ZooKeeperConnection Watcher:127.0.0.1:50488 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2424246 T3904 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2424250 T3904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2424276 T3904 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2424281 T3944 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d97869f name:ZooKeeperConnection Watcher:127.0.0.1:50488/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2424281 T3904 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2424297 T3904 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2425307 T3904 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50495_
[junit4:junit4] 2> 2425310 T3904 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50495_
[junit4:junit4] 2> 2425319 T3944 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 2425320 T3931 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 2425325 T3926 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 2425332 T3904 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 2425333 T3904 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2425333 T3904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2425974 T3904 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2425981 T3904 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50498
[junit4:junit4] 2> 2425986 T3904 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2425987 T3904 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2425987 T3904 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-1369732133159
[junit4:junit4] 2> 2425988 T3904 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-1369732133159/solr.xml
[junit4:junit4] 2> 2425989 T3904 oasc.CoreContainer.<init> New CoreContainer 343671018
[junit4:junit4] 2> 2425991 T3904 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-1369732133159/'
[junit4:junit4] 2> 2425992 T3904 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-1369732133159/'
[junit4:junit4] 2> 2426235 T3904 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-1369732133159
[junit4:junit4] 2> 2426236 T3904 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-1369732133159/collection1
[junit4:junit4] 2> 2426238 T3904 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-1369732133159/collection1/conf
[junit4:junit4] 2> 2426430 T3904 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-1369732133159/collection1/conf/xslt
[junit4:junit4] 2> 2426434 T3904 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-1369732133159/collection1/lib
[junit4:junit4] 2> 2426437 T3904 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-1369732133159/collection1/lib/classes
[junit4:junit4] 2> 2426439 T3904 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-1369732133159/conf/core.properties, adding to cores
[junit4:junit4] 2> 2426462 T3904 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 2426463 T3904 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2426463 T3904 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 2426464 T3904 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2426464 T3904 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2426465 T3904 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2426465 T3904 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2426466 T3904 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2426466 T3904 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2426469 T3904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 2426496 T3904 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2426497 T3904 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50488/solr
[junit4:junit4] 2> 2426498 T3904 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2426500 T3904 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2426507 T3956 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@29ea48eb name:ZooKeeperConnection Watcher:127.0.0.1:50488 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2426509 T3904 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2426515 T3904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2426544 T3904 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2426548 T3958 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4dabe9ae name:ZooKeeperConnection Watcher:127.0.0.1:50488/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2426549 T3904 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2426561 T3904 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2427571 T3904 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50498_
[junit4:junit4] 2> 2427575 T3904 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50498_
[junit4:junit4] 2> 2427589 T3958 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 2427589 T3926 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 2427590 T3931 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 2427590 T3944 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 2427635 T3904 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 2427636 T3904 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2427636 T3904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2428525 T3904 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2428539 T3904 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50501
[junit4:junit4] 2> 2428543 T3904 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2428544 T3904 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2428544 T3904 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-1369732135468
[junit4:junit4] 2> 2428545 T3904 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-1369732135468/solr.xml
[junit4:junit4] 2> 2428545 T3904 oasc.CoreContainer.<init> New CoreContainer 83460965
[junit4:junit4] 2> 2428546 T3904 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-1369732135468/'
[junit4:junit4] 2> 2428547 T3904 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-1369732135468/'
[junit4:junit4] 2> 2428829 T3904 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-1369732135468
[junit4:junit4] 2> 2428831 T3904 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-1369732135468/collection1
[junit4:junit4] 2> 2428833 T3904 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-1369732135468/collection1/conf
[junit4:junit4] 2> 2429143 T3904 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-1369732135468/collection1/conf/xslt
[junit4:junit4] 2> 2429156 T3904 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-1369732135468/collection1/lib
[junit4:junit4] 2> 2429158 T3904 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-1369732135468/collection1/lib/classes
[junit4:junit4] 2> 2429161 T3904 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-1369732135468/conf/core.properties, adding to cores
[junit4:junit4] 2> 2429179 T3904 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 2429180 T3904 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2429181 T3904 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 2429182 T3904 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2429182 T3904 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2429183 T3904 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2429183 T3904 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2429194 T3904 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2429195 T3904 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2429195 T3904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 2429248 T3904 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2429249 T3904 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50488/solr
[junit4:junit4] 2> 2429249 T3904 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2429264 T3904 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2429284 T3970 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5c505450 name:ZooKeeperConnection Watcher:127.0.0.1:50488 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2429297 T3904 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2429307 T3904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2429358 T3904 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2429364 T3972 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@34089ba2 name:ZooKeeperConnection Watcher:127.0.0.1:50488/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2429366 T3904 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2429398 T3904 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2430422 T3904 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50501_
[junit4:junit4] 2> 2430426 T3904 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50501_
[junit4:junit4] 2> 2430443 T3972 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2430443 T3944 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2430443 T3926 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2430448 T3958 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2430448 T3931 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2430469 T3904 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 2430470 T3904 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2430471 T3904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2431496 T3904 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2431509 T3904 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50504
[junit4:junit4] 2> 2431512 T3904 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2431513 T3904 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2431514 T3904 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-1369732138307
[junit4:junit4] 2> 2431514 T3904 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-1369732138307/solr.xml
[junit4:junit4] 2> 2431515 T3904 oasc.CoreContainer.<init> New CoreContainer 292444501
[junit4:junit4] 2> 2431516 T3904 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-1369732138307/'
[junit4:junit4] 2> 2431517 T3904 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-1369732138307/'
[junit4:junit4] 2> 2431745 T3904 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-1369732138307
[junit4:junit4] 2> 2431748 T3904 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-1369732138307/collection1
[junit4:junit4] 2> 2431754 T3904 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-1369732138307/collection1/conf
[junit4:junit4] 2> 2432092 T3904 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-1369732138307/collection1/conf/xslt
[junit4:junit4] 2> 2432099 T3904 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-1369732138307/collection1/lib
[junit4:junit4] 2> 2432103 T3904 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-1369732138307/collection1/lib/classes
[junit4:junit4] 2> 2432107 T3904 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-1369732138307/conf/core.properties, adding to cores
[junit4:junit4] 2> 2432138 T3904 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
[junit4:junit4] 2> 2432140 T3904 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2432143 T3904 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
[junit4:junit4] 2> 2432143 T3904 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2432144 T3904 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2432144 T3904 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2432145 T3904 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2432146 T3904 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2432146 T3904 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2432147 T3904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=0&connTimeout=0&retry=false
[junit4:junit4] 2> 2432185 T3904 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2432186 T3904 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50488/solr
[junit4:junit4] 2> 2432188 T3904 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2432199 T3904 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2432202 T3984 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@34d8d455 name:ZooKeeperConnection Watcher:127.0.0.1:50488 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2432211 T3904 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2432221 T3904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2432278 T3904 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2432284 T3986 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3762e005 name:ZooKeeperConnection Watcher:127.0.0.1:50488/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2432285 T3904 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2432324 T3904 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2433367 T3904 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50504_
[junit4:junit4] 2> 2433371 T3904 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50504_
[junit4:junit4] 2> 2433383 T3926 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2433384 T3986 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2433384 T3944 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2433383 T3931 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2433384 T3958 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2433384 T3972 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2433404 T3904 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 2433405 T3904 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2433406 T3904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2433438 T3904 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2433478 T3938 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=2&name=nodes_used_collection&replicationFactor=2&action=CREATE&wt=javabin&version=2
[junit4:junit4] 2> 2433484 T3926 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 2433491 T3928 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> 2433492 T3928 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:50504_
[junit4:junit4] 2> 2433493 T3928 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:50498_
[junit4:junit4] 2> 2433494 T3928 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:50495_
[junit4:junit4] 2> 2433504 T3928 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:50501_
[junit4:junit4] 2> 2433524 T3963 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-1369732135468/nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 2433525 T3963 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 2433525 T3981 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard1_replica1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369732138307/nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2433527 T3981 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 2433525 T3954 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard1_replica2' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369732133159/nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 2433528 T3954 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 2433527 T3939 oasc.CoreContainer.create Creating SolrCore 'nodes_used_collection_shard2_replica1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369732130861/nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 2433529 T3939 oasc.ZkController.createCollectionZkNode Check for collection zkNode:nodes_used_collection
[junit4:junit4] 2> 2433531 T3963 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 2433531 T3963 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2433532 T3954 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 2433532 T3954 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2433531 T3981 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 2433534 T3981 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2433532 T3939 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:nodes_used_collection
[junit4:junit4] 2> 2433535 T3939 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2433540 T3954 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 2433540 T3939 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 2433541 T3939 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 2433540 T3963 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 2433543 T3963 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 2433541 T3981 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 2433544 T3981 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 2433541 T3954 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection
[junit4:junit4] 2> 2433563 T3939 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 2433565 T3981 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 2433565 T3954 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 2433566 T3963 oasc.ZkController.readConfigName Load collection config from:/collections/nodes_used_collection
[junit4:junit4] 2> 2433572 T3954 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-1369732133159/nodes_used_collection_shard1_replica2/'
[junit4:junit4] 2> 2433573 T3981 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-1369732138307/nodes_used_collection_shard1_replica1/'
[junit4:junit4] 2> 2433572 T3939 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-1369732130861/nodes_used_collection_shard2_replica1/'
[junit4:junit4] 2> 2433587 T3963 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-1369732135468/nodes_used_collection_shard2_replica2/'
[junit4:junit4] 2> 2433855 T3963 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2433884 T3939 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2433915 T3954 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2434004 T3981 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2434180 T3939 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2434202 T3939 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2434219 T3963 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2434254 T3963 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2434260 T3954 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2434265 T3963 oass.IndexSchema.readSchema [nodes_used_collection_shard2_replica2] Schema name=test
[junit4:junit4] 2> 2434272 T3954 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2434276 T3939 oass.IndexSchema.readSchema [nodes_used_collection_shard2_replica1] Schema name=test
[junit4:junit4] 2> 2434289 T3954 oass.IndexSchema.readSchema [nodes_used_collection_shard1_replica2] Schema name=test
[junit4:junit4] 2> 2434395 T3981 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2434405 T3981 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2434414 T3981 oass.IndexSchema.readSchema [nodes_used_collection_shard1_replica1] Schema name=test
[junit4:junit4] 2> 2437808 T3939 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2437868 T3939 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2437910 T3954 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2437913 T3981 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2437926 T3981 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2437931 T3981 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2437937 T3963 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2437943 T3954 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2437936 T3939 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2437962 T3954 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2437993 T3963 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2438012 T3963 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2438095 T3939 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2438095 T3954 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2438128 T3939 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2438129 T3981 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2438145 T3954 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2438147 T3981 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2438156 T3939 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2438168 T3939 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2438172 T3939 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2438174 T3954 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2438174 T3939 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2438180 T3939 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2438180 T3939 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2438184 T3939 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2438194 T3939 oasc.SolrCore.<init> [nodes_used_collection_shard2_replica1] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369732130861/nodes_used_collection_shard2_replica1/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369732130861/nodes_used_collection_shard2_replica1/data/
[junit4:junit4] 2> 2438194 T3939 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4d3f83b5
[junit4:junit4] 2> 2438194 T3954 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2438211 T3954 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2438215 T3954 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2438194 T3981 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2438208 T3963 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2438197 T3939 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2438221 T3939 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-1369732130861/nodes_used_collection_shard2_replica1/data
[junit4:junit4] 2> 2438221 T3939 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-1369732130861/nodes_used_collection_shard2_replica1/data/index/
[junit4:junit4] 2> 2438222 T3939 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard2_replica1] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1369732130861/nodes_used_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2438223 T3939 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-1369732130861/nodes_used_collection_shard2_replica1/data/index
[junit4:junit4] 2> 2438230 T3954 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2438231 T3954 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2438231 T3954 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2438232 T3954 oasc.SolrCore.<init> [nodes_used_collection_shard1_replica2] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369732133159/nodes_used_collection_shard1_replica2/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369732133159/nodes_used_collection_shard1_replica2/data/
[junit4:junit4] 2> 2438233 T3954 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4d3f83b5
[junit4:junit4] 2> 2438233 T3954 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2438234 T3954 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369732133159/nodes_used_collection_shard1_replica2/data
[junit4:junit4] 2> 2438235 T3954 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369732133159/nodes_used_collection_shard1_replica2/data/index/
[junit4:junit4] 2> 2438235 T3954 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard1_replica2] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369732133159/nodes_used_collection_shard1_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2438236 T3981 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2438237 T3981 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2438237 T3981 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2438239 T3954 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369732133159/nodes_used_collection_shard1_replica2/data/index
[junit4:junit4] 2> 2438240 T3963 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2438256 T3939 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7bc2c7d9 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6003e06d),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2438258 T3939 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2438257 T3981 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2438268 T3939 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2438269 T3939 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2438271 T3939 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2438272 T3939 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2438273 T3939 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2438274 T3939 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2438274 T3939 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2438268 T3981 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2438282 T3981 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2438283 T3981 oasc.SolrCore.<init> [nodes_used_collection_shard1_replica1] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369732138307/nodes_used_collection_shard1_replica1/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369732138307/nodes_used_collection_shard1_replica1/data/
[junit4:junit4] 2> 2438283 T3981 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4d3f83b5
[junit4:junit4] 2> 2438282 T3939 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2438285 T3939 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2438281 T3963 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2438269 T3954 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@76bea5e lockFactory=org.apache.lucene.store.NativeFSLockFactory@1abe67c3),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2438289 T3954 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2438284 T3981 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2438296 T3981 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-1369732138307/nodes_used_collection_shard1_replica1/data
[junit4:junit4] 2> 2438296 T3981 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-1369732138307/nodes_used_collection_shard1_replica1/data/index/
[junit4:junit4] 2> 2438297 T3981 oasc.SolrCore.initIndex WARN [nodes_used_collection_shard1_replica1] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369732138307/nodes_used_collection_shard1_replica1/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2438296 T3963 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2438301 T3963 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2438301 T3963 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2438309 T3981 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-1369732138307/nodes_used_collection_shard1_replica1/data/index
[junit4:junit4] 2> 2438323 T3954 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2438324 T3954 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2438326 T3963 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2438328 T3963 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2438328 T3963 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2438330 T3954 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2438333 T3954 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2438334 T3954 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2438335 T3954 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2438336 T3954 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2438363 T3954 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2438364 T3954 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2438367 T3981 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@25e0b376 lockFactory=org.apache.lucene.store.NativeFSLockFactory@156ddeb8),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2438368 T3981 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2438373 T3939 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2438362 T3963 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-1369732135468/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-1369732135468/nodes_used_collection_shard2_replica2/data/
[junit4:junit4] 2> 2438379 T3963 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4d3f83b5
[junit4:junit4] 2> 2438380 T3963 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2438382 T3963 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-1369732135468/nodes_used_collection_shard2_replica2/data
[junit4:junit4] 2> 2438383 T3963 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-1369732135468/nodes_used_collection_shard2_replica2/data/index/
[junit4:junit4] 2> 2438385 T3963 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-1369732135468/nodes_used_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2438396 T3981 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2438396 T3981 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2438403 T3981 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2438404 T3963 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-1369732135468/nodes_used_collection_shard2_replica2/data/index
[junit4:junit4] 2> 2438412 T3954 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2438404 T3981 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2438431 T3981 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2438431 T3981 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2438432 T3981 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2438433 T3981 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2438434 T3981 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2438442 T3963 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@f22bd6b lockFactory=org.apache.lucene.store.NativeFSLockFactory@4e2c3df2),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2438443 T3963 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2438443 T3981 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2438458 T3963 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2438458 T3963 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2438461 T3963 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2438462 T3963 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2438463 T3963 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2438463 T3963 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2438465 T3963 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2438471 T3963 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2438473 T3963 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2438485 T3939 oass.SolrIndexSearcher.<init> Opening Searcher@7b224181 main
[junit4:junit4] 2> 2438489 T3939 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-1369732130861/nodes_used_collection_shard2_replica1/data/tlog
[junit4:junit4] 2> 2438491 T3939 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2438492 T3939 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2438507 T3954 oass.SolrIndexSearcher.<init> Opening Searcher@2cf4f95b main
[junit4:junit4] 2> 2438508 T3992 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica1] Registered new searcher Searcher@7b224181 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2438508 T3954 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369732133159/nodes_used_collection_shard1_replica2/data/tlog
[junit4:junit4] 2> 2438511 T3954 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2438512 T3954 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2438511 T3939 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica1 state=down
[junit4:junit4] 2> 2438521 T3993 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica2] Registered new searcher Searcher@2cf4f95b main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2438523 T3954 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica2 state=down
[junit4:junit4] 2> 2438537 T3963 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2438543 T3981 oass.SolrIndexSearcher.<init> Opening Searcher@38eb52c4 main
[junit4:junit4] 2> 2438543 T3981 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-1369732138307/nodes_used_collection_shard1_replica1/data/tlog
[junit4:junit4] 2> 2438545 T3981 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2438545 T3981 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2438554 T3994 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica1] Registered new searcher Searcher@38eb52c4 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2438556 T3981 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=down
[junit4:junit4] 2> 2438559 T3963 oass.SolrIndexSearcher.<init> Opening Searcher@3b89a65c main
[junit4:junit4] 2> 2438559 T3963 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-1369732135468/nodes_used_collection_shard2_replica2/data/tlog
[junit4:junit4] 2> 2438561 T3963 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2438562 T3963 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2438571 T3995 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica2] Registered new searcher Searcher@3b89a65c main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2438578 T3963 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica2 state=down
[junit4:junit4] 2> 2439706 T3927 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2439711 T3927 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:50495_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50495"}
[junit4:junit4] 2> 2439711 T3927 oasc.Overseer$ClusterStateUpdater.createCollection Create collection nodes_used_collection with numShards 2
[junit4:junit4] 2> 2440468 T3927 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:50498_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50498"}
[junit4:junit4] 2> 2440480 T3927 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:50504_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50504"}
[junit4:junit4] 2> 2440492 T3927 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:50501_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50501"}
[junit4:junit4] 2> 2440506 T3986 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> 2440508 T3972 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> 2440509 T3926 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> 2440510 T3931 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> 2440511 T3944 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> 2440513 T3958 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> 2440538 T3939 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard2_replica1
[junit4:junit4] 2> 2440539 T3939 oasc.ZkController.register Register replica - core:nodes_used_collection_shard2_replica1 address:http://127.0.0.1:50495 collection:nodes_used_collection shard:shard2
[junit4:junit4] 2> 2440539 T3954 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard1_replica2
[junit4:junit4] 2> 2440540 T3954 oasc.ZkController.register Register replica - core:nodes_used_collection_shard1_replica2 address:http://127.0.0.1:50498 collection:nodes_used_collection shard:shard1
[junit4:junit4] 2> 2440542 T3954 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard1/election
[junit4:junit4] 2> 2440544 T3939 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leader_elect/shard2/election
[junit4:junit4] 2> 2440577 T3981 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2440578 T3981 oasc.ZkController.register Register replica - core:nodes_used_collection_shard1_replica1 address:http://127.0.0.1:50504 collection:nodes_used_collection shard:shard1
[junit4:junit4] 2> 2440583 T3954 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 2440585 T3939 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 2440592 T3963 oasc.CoreContainer.registerCore registering core: nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 2440592 T3963 oasc.ZkController.register Register replica - core:nodes_used_collection_shard2_replica2 address:http://127.0.0.1:50501 collection:nodes_used_collection shard:shard2
[junit4:junit4] 2> 2440602 T3939 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 2440603 T3939 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 2440603 T3939 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50495/nodes_used_collection_shard2_replica1/
[junit4:junit4] 2> 2440604 T3939 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica1 url=http://127.0.0.1:50495 START replicas=[http://127.0.0.1:50501/nodes_used_collection_shard2_replica2/] nUpdates=100
[junit4:junit4] 2> 2440605 T3939 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica1 url=http://127.0.0.1:50495 DONE. We have no versions. sync failed.
[junit4:junit4] 2> 2440606 T3939 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4] 2> 2440607 T3939 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> 2440609 T3939 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50495/nodes_used_collection_shard2_replica1/
[junit4:junit4] 2> 2440610 T3939 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leaders/shard2
[junit4:junit4] 2> 2440609 T3954 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 2440611 T3954 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 2440611 T3954 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50498/nodes_used_collection_shard1_replica2/
[junit4:junit4] 2> 2440612 T3954 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica2 url=http://127.0.0.1:50498 START replicas=[http://127.0.0.1:50504/nodes_used_collection_shard1_replica1/] nUpdates=100
[junit4:junit4] 2> 2440614 T3954 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica2 url=http://127.0.0.1:50498 DONE. We have no versions. sync failed.
[junit4:junit4] 2> 2440615 T3954 oasc.SyncStrategy.syncReplicas Leader's attempt to sync with shard failed, moving to the next canidate
[junit4:junit4] 2> 2440616 T3954 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> 2440616 T3954 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50498/nodes_used_collection_shard1_replica2/
[junit4:junit4] 2> 2440616 T3954 oascc.SolrZkClient.makePath makePath: /collections/nodes_used_collection/leaders/shard1
[junit4:junit4] 2> ASYNC NEW_CORE C769 name=nodes_used_collection_shard2_replica2 org.apache.solr.core.SolrCore@39ef8678 url=http://127.0.0.1:50501/nodes_used_collection_shard2_replica2 node=127.0.0.1:50501_ C769_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica2 props:{shard=shard2, state=down, core=nodes_used_collection_shard2_replica2, collection=nodes_used_collection, node_name=127.0.0.1:50501_, base_url=http://127.0.0.1:50501}
[junit4:junit4] 2> 2440635 T3965 C769 P50501 oasc.SolrCore.execute [nodes_used_collection_shard2_replica2] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=13
[junit4:junit4] 2> ASYNC NEW_CORE C770 name=nodes_used_collection_shard1_replica1 org.apache.solr.core.SolrCore@3bcf8af9 url=http://127.0.0.1:50504/nodes_used_collection_shard1_replica1 node=127.0.0.1:50504_ C770_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:50504_, base_url=http://127.0.0.1:50504}
[junit4:junit4] 2> 2440641 T3977 C770 P50504 oasc.SolrCore.execute [nodes_used_collection_shard1_replica1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4:junit4] 2> 2442075 T3927 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2442119 T3944 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> 2442125 T3926 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> 2442126 T3972 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> 2442126 T3958 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> 2442128 T3986 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> 2442129 T3931 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> 2442147 T3939 oasc.ZkController.register We are http://127.0.0.1:50495/nodes_used_collection_shard2_replica1/ and leader is http://127.0.0.1:50495/nodes_used_collection_shard2_replica1/
[junit4:junit4] 2> 2442148 T3939 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard2_replica1 baseURL=http://127.0.0.1:50495
[junit4:junit4] 2> 2442149 T3939 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 2442150 T3939 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica1 state=active
[junit4:junit4] 2> 2442151 T3963 oasc.ZkController.register We are http://127.0.0.1:50501/nodes_used_collection_shard2_replica2/ and leader is http://127.0.0.1:50495/nodes_used_collection_shard2_replica1/
[junit4:junit4] 2> 2442151 T3963 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard2_replica2 baseURL=http://127.0.0.1:50501
[junit4:junit4] 2> 2442152 T3963 oasc.ZkController.checkRecovery Core needs to recover:nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 2442152 T3963 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> 2442153 T3954 oasc.ZkController.register We are http://127.0.0.1:50498/nodes_used_collection_shard1_replica2/ and leader is http://127.0.0.1:50498/nodes_used_collection_shard1_replica2/
[junit4:junit4] 2> 2442154 T3954 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard1_replica2 baseURL=http://127.0.0.1:50498
[junit4:junit4] 2> 2442154 T3954 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 2442155 T3954 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica2 state=active
[junit4:junit4] 2> 2442159 T3998 C769 P50501 oasc.RecoveryStrategy.run Starting recovery process. core=nodes_used_collection_shard2_replica2 recoveringAfterStartup=true
[junit4:junit4] 2> 2442160 T3998 C769 P50501 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 2442161 T3998 C769 P50501 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica2 state=recovering
[junit4:junit4] 2> 2442163 T3963 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2442166 T3998 C769 P50501 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2442166 T3939 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2442168 T3963 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=8644
[junit4:junit4] 2> 2442170 T3939 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=8643
[junit4:junit4] 2> 2442171 T3954 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2442172 T3954 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=8647
[junit4:junit4] 2> 2442178 T3981 oasc.ZkController.register We are http://127.0.0.1:50504/nodes_used_collection_shard1_replica1/ and leader is http://127.0.0.1:50498/nodes_used_collection_shard1_replica2/
[junit4:junit4] 2> 2442179 T3981 oasc.ZkController.register No LogReplay needed for core=nodes_used_collection_shard1_replica1 baseURL=http://127.0.0.1:50504
[junit4:junit4] 2> 2442179 T3981 oasc.ZkController.checkRecovery Core needs to recover:nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2442180 T3981 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> 2442181 T3999 C770 P50504 oasc.RecoveryStrategy.run Starting recovery process. core=nodes_used_collection_shard1_replica1 recoveringAfterStartup=true
[junit4:junit4] 2> 2442182 T3999 C770 P50504 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 2442183 T3999 C770 P50504 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=recovering
[junit4:junit4] 2> 2442184 T3981 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2442187 T3999 C770 P50504 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2442197 T3981 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=8673
[junit4:junit4] 2> 2442209 T3928 oasc.OverseerCollectionProcessor.createCollection Finished create command on all shards for collection: nodes_used_collection
[junit4:junit4] 2> 2442231 T3950 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:50504__nodes_used_collection_shard1_replica1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 2442234 T3935 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:50501__nodes_used_collection_shard2_replica2, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 2442242 T3944 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work/qnr-0000000000 state: SyncConnected type NodeDataChanged
[junit4:junit4] 2> 2442249 T3938 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=8771
[junit4:junit4] 2> 2442250 T3904 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 2442253 T3904 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2442259 T4001 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@23bfc909 name:ZooKeeperConnection Watcher:127.0.0.1:50488/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2442260 T3904 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2442260 T3928 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Message id:/overseer/collection-queue-work/qn-0000000000 complete, response:{success={null={responseHeader={status=0,QTime=8647},core=nodes_used_collection_shard1_replica2},null={responseHeader={status=0,QTime=8644},core=nodes_used_collection_shard2_replica2},null={responseHeader={status=0,QTime=8643},core=nodes_used_collection_shard2_replica1},null={responseHeader={status=0,QTime=8673},core=nodes_used_collection_shard1_replica1}}}
[junit4:junit4] 2> 2442261 T3926 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 2442264 T3904 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2442276 T3904 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 2442284 T3904 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2442291 T4003 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15529275 name:ZooKeeperConnection Watcher:127.0.0.1:50488/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2442291 T3904 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2442295 T3904 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2442341 T3951 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=2&maxShardsPerNode=2&name=awholynewcollection_0&replicationFactor=4&action=CREATE&wt=javabin&version=2
[junit4:junit4] 2> 2442345 T3926 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4:junit4] 2> 2442349 T3928 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":"2",
[junit4:junit4] 2> "maxShardsPerNode":"2",
[junit4:junit4] 2> "createNodeSet":null,
[junit4:junit4] 2> "name":"awholynewcollection_0",
[junit4:junit4] 2> "replicationFactor":"4"}
[junit4:junit4] 2> 2442350 T3928 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica1 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:50501_
[junit4:junit4] 2> 2442350 T3928 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica2 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:50495_
[junit4:junit4] 2> 2442351 T3928 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica3 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:50498_
[junit4:junit4] 2> 2442352 T3928 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard1_replica4 as part of slice shard1 of collection awholynewcollection_0 on 127.0.0.1:50491_
[junit4:junit4] 2> 2442357 T3952 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-jetty2-1369732133159/awholynewcollection_0_shard1_replica3
[junit4:junit4] 2> 2442360 T3952 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2442360 T3936 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-jetty1-1369732130861/awholynewcollection_0_shard1_replica2
[junit4:junit4] 2> 2442362 T3936 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2442360 T3964 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-jetty3-1369732135468/awholynewcollection_0_shard1_replica1
[junit4:junit4] 2> 2442363 T3964 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2442353 T3928 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica1 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:50504_
[junit4:junit4] 2> 2442361 T3922 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-controljetty-1369732129298/awholynewcollection_0_shard1_replica4
[junit4:junit4] 2> 2442366 T3922 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2442365 T3964 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 2442365 T3936 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 2442368 T3936 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2442365 T3952 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 2442367 T3964 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2442367 T3928 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica2 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:50501_
[junit4:junit4] 2> 2442372 T3982 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-jetty4-1369732138307/awholynewcollection_0_shard2_replica1
[junit4:junit4] 2> 2442372 T3982 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2442370 T3952 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2442374 T3928 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica3 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:50495_
[junit4:junit4] 2> 2442378 T3966 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-jetty3-1369732135468/awholynewcollection_0_shard2_replica2
[junit4:junit4] 2> 2442380 T3966 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2442382 T3937 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-jetty1-1369732130861/awholynewcollection_0_shard2_replica3
[junit4:junit4] 2> 2442383 T3937 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2442385 T3936 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 2442386 T3936 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 2442387 T3922 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 2442388 T3922 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2442389 T3966 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 2442389 T3966 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2442378 T3928 oasc.OverseerCollectionProcessor.createCollection Creating shard awholynewcollection_0_shard2_replica4 as part of slice shard2 of collection awholynewcollection_0 on 127.0.0.1:50498_
[junit4:junit4] 2> 2442389 T3964 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 2442392 T3964 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 2442387 T3952 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 2442393 T3952 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 2442387 T3937 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 2442382 T3982 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:awholynewcollection_0
[junit4:junit4] 2> 2442400 T3982 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2442399 T3937 oasc.ZkController.getConfName Looking for collection configName
[junit4:junit4] 2> 2442398 T3953 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-jetty2-1369732133159/awholynewcollection_0_shard2_replica4
[junit4:junit4] 2> 2442403 T3953 oasc.ZkController.createCollectionZkNode Check for collection zkNode:awholynewcollection_0
[junit4:junit4] 2> 2442403 T3936 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2442406 T3922 oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
[junit4:junit4] 2> 2442407 T3922 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 2442407 T3953 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2442408 T3953 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2442407 T3966 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 2442409 T3982 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 2442419 T3964 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2442421 T3937 oascc.SolrZkClient.makePath makePath: /collections/awholynewcollection_0
[junit4:junit4] 2> 2442423 T3936 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-1369732130861/awholynewcollection_0_shard1_replica2/'
[junit4:junit4] 2> 2442424 T3952 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2442436 T3953 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-1369732133159/awholynewcollection_0_shard2_replica4/'
[junit4:junit4] 2> 2442445 T3982 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2442447 T3966 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2442447 T3964 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-1369732135468/awholynewcollection_0_shard1_replica1/'
[junit4:junit4] 2> 2442451 T3952 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-1369732133159/awholynewcollection_0_shard1_replica3/'
[junit4:junit4] 2> 2442452 T3922 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2442454 T3937 oasc.ZkController.readConfigName Load collection config from:/collections/awholynewcollection_0
[junit4:junit4] 2> 2442472 T3922 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-1369732129298/awholynewcollection_0_shard1_replica4/'
[junit4:junit4] 2> 2442475 T3966 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-1369732135468/awholynewcollection_0_shard2_replica2/'
[junit4:junit4] 2> 2442478 T3982 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-1369732138307/awholynewcollection_0_shard2_replica1/'
[junit4:junit4] 2> 2442489 T3937 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-1369732130861/awholynewcollection_0_shard2_replica3/'
[junit4:junit4] 2> 2442820 T3982 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2442835 T3966 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2442837 T3964 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2442890 T3953 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2442951 T3952 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2442973 T3936 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2442999 T3937 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2443063 T3922 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2443289 T3936 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2443324 T3936 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2443328 T3982 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2443360 T3936 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica2] Schema name=test
[junit4:junit4] 2> 2443368 T3982 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2443414 T3964 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2443419 T3937 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2443420 T3982 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica1] Schema name=test
[junit4:junit4] 2> 2443442 T3937 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2443439 T3964 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2443450 T3937 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica3] Schema name=test
[junit4:junit4] 2> 2443451 T3964 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica1] Schema name=test
[junit4:junit4] 2> 2443453 T3952 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2443475 T3953 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2443494 T3953 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2443495 T3952 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2443516 T3953 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica4] Schema name=test
[junit4:junit4] 2> 2443561 T3952 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica3] Schema name=test
[junit4:junit4] 2> 2443573 T3966 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2443583 T3922 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2443608 T3966 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2443610 T3922 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2443618 T3922 oass.IndexSchema.readSchema [awholynewcollection_0_shard1_replica4] Schema name=test
[junit4:junit4] 2> 2443627 T3966 oass.IndexSchema.readSchema [awholynewcollection_0_shard2_replica2] Schema name=test
[junit4:junit4] 2> 2443802 T3927 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2443805 T3927 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:50495__nodes_used_collection_shard2_replica1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"nodes_used_collection_shard2_replica1",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50495_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50495"}
[junit4:junit4] 2> 2443826 T3927 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:50498__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:50498_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50498"}
[junit4:junit4] 2> 2443846 T3927 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:50501__nodes_used_collection_shard2_replica2",
[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_replica2",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50501_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50501"}
[junit4:junit4] 2> 2443879 T3927 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:50504__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:50504_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50504"}
[junit4:junit4] 2> 2443902 T4001 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> 2443903 T4003 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> 2443903 T3931 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> 2443903 T3958 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> 2443905 T3972 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> 2443906 T3944 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> 2443906 T3986 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> 2443910 T3926 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> 2444235 T3950 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:50504__nodes_used_collection_shard1_replica1, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 2444236 T3950 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:50504__nodes_used_collection_shard1_replica1&state=recovering&nodeName=127.0.0.1:50504_&action=PREPRECOVERY&checkLive=true&core=nodes_used_collection_shard1_replica2&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2005
[junit4:junit4] 2> 2444237 T3935 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:50501__nodes_used_collection_shard2_replica2, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 2444238 T3935 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:50501__nodes_used_collection_shard2_replica2&state=recovering&nodeName=127.0.0.1:50501_&action=PREPRECOVERY&checkLive=true&core=nodes_used_collection_shard2_replica1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2004
[junit4:junit4] 2> ASYNC NEW_CORE C771 name=nodes_used_collection_shard1_replica1 org.apache.solr.core.SolrCore@3bcf8af9 url=http://127.0.0.1:50504/nodes_used_collection_shard1_replica1 node=127.0.0.1:50504_ C771_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:50504_, base_url=http://127.0.0.1:50504}
[junit4:junit4] 2> 2446239 T3999 C771 P50504 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:50498/nodes_used_collection_shard1_replica2/ core=nodes_used_collection_shard1_replica1 - recoveringAfterStartup=true
[junit4:junit4] 2> 2446240 T3999 C771 P50504 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard1_replica1 url=http://127.0.0.1:50504 START replicas=[http://127.0.0.1:50498/nodes_used_collection_shard1_replica2/] nUpdates=100
[junit4:junit4] 2> 2446241 T3999 C771 P50504 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 2446242 T3999 C771 P50504 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2446242 T3999 C771 P50504 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2446248 T3999 C771 P50504 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2446249 T3999 C771 P50504 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 2446249 T3999 C771 P50504 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:50498/nodes_used_collection_shard1_replica2/. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2446249 T3999 C771 P50504 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C772 name=nodes_used_collection_shard2_replica2 org.apache.solr.core.SolrCore@39ef8678 url=http://127.0.0.1:50501/nodes_used_collection_shard2_replica2 node=127.0.0.1:50501_ C772_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica2 props:{shard=shard2, state=recovering, core=nodes_used_collection_shard2_replica2, collection=nodes_used_collection, node_name=127.0.0.1:50501_, base_url=http://127.0.0.1:50501}
[junit4:junit4] 2> 2446242 T3998 C772 P50501 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:50495/nodes_used_collection_shard2_replica1/ core=nodes_used_collection_shard2_replica2 - recoveringAfterStartup=true
[junit4:junit4] 2> 2446253 T3998 C772 P50501 oasu.PeerSync.sync PeerSync: core=nodes_used_collection_shard2_replica2 url=http://127.0.0.1:50501 START replicas=[http://127.0.0.1:50495/nodes_used_collection_shard2_replica1/] nUpdates=100
[junit4:junit4] 2> 2446255 T3998 C772 P50501 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 2446255 T3998 C772 P50501 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 2446256 T3998 C772 P50501 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 2446256 T3998 C772 P50501 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 2446256 T3998 C772 P50501 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 2446257 T3998 C772 P50501 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:50495/nodes_used_collection_shard2_replica1/. core=nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 2446257 T3998 C772 P50501 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C773 name=nodes_used_collection_shard1_replica2 org.apache.solr.core.SolrCore@3c3e275c url=http://127.0.0.1:50498/nodes_used_collection_shard1_replica2 node=127.0.0.1:50498_ C773_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:50498_, base_url=http://127.0.0.1:50498, leader=true}
[junit4:junit4] 2> 2446373 T3950 C773 P50498 oasc.SolrCore.execute [nodes_used_collection_shard1_replica2] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=9
[junit4:junit4] 2> 2446384 T3949 C773 P50498 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 2446410 T3949 C773 P50498 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@76bea5e lockFactory=org.apache.lucene.store.NativeFSLockFactory@1abe67c3),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2446412 T3949 C773 P50498 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2446414 T3949 C773 P50498 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@76bea5e lockFactory=org.apache.lucene.store.NativeFSLockFactory@1abe67c3),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@76bea5e lockFactory=org.apache.lucene.store.NativeFSLockFactory@1abe67c3),segFN=segments_2,generation=2}
[junit4:junit4] 2> 2446415 T3949 C773 P50498 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 2446443 T3949 C773 P50498 oass.SolrIndexSearcher.<init> Opening Searcher@5cbef89d realtime
[junit4:junit4] 2> ASYNC NEW_CORE C774 name=nodes_used_collection_shard1_replica2 org.apache.solr.core.SolrCore@3c3e275c url=http://127.0.0.1:50498/nodes_used_collection_shard1_replica2 node=127.0.0.1:50498_ C774_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:50498_, base_url=http://127.0.0.1:50498, leader=true}
[junit4:junit4] 2> 2446526 T3949 C774 P50498 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 2446527 T3949 C774 P50498 oasup.LogUpdateProcessor.finish [nodes_used_collection_shard1_replica2] webapp= path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 143
[junit4:junit4] 2> ASYNC NEW_CORE C775 name=nodes_used_collection_shard1_replica1 org.apache.solr.core.SolrCore@3bcf8af9 url=http://127.0.0.1:50504/nodes_used_collection_shard1_replica1 node=127.0.0.1:50504_ C775_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:50504_, base_url=http://127.0.0.1:50504}
[junit4:junit4] 2> 2446538 T3999 C775 P50504 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 2446538 T3999 C775 P50504 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 2446586 T3954 C774 P50498 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 2446588 T3954 C774 P50498 oasc.SolrCore.execute [nodes_used_collection_shard1_replica2] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=6
[junit4:junit4] 2> 2446594 T3999 C775 P50504 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 2446596 T3999 C775 P50504 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 2446596 T3999 C775 P50504 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 2446623 T3950 C774 P50498 oasc.SolrCore.execute [nodes_used_collection_shard1_replica2] webapp= path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=0
[junit4:junit4] 2> 2446625 T3999 C775 P50504 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 2446629 T3999 C775 P50504 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-1369732138307/nodes_used_collection_shard1_replica1/data/index.20130528020914429
[junit4:junit4] 2> 2446630 T3999 C775 P50504 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@7e3a3051 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6111268b) fullCopy=false
[junit4:junit4] 2> ASYNC NEW_CORE C776 name=nodes_used_collection_shard2_replica1 org.apache.solr.core.SolrCore@1ddc755a url=http://127.0.0.1:50495/nodes_used_collection_shard2_replica1 node=127.0.0.1:50495_ C776_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica1 props:{shard=shard2, state=active, core=nodes_used_collection_shard2_replica1, collection=nodes_used_collection, node_name=127.0.0.1:50495_, base_url=http://127.0.0.1:50495, leader=true}
[junit4:junit4] 2> 2446636 T3939 C776 P50495 oasc.SolrCore.execute [nodes_used_collection_shard2_replica1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 2446639 T3940 C776 P50495 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 2446641 T3949 C774 P50498 oasc.SolrCore.execute [nodes_used_collection_shard1_replica2] webapp= path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=1
[junit4:junit4] 2> 2446657 T3999 C775 P50504 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 2446709 T3940 C776 P50495 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7bc2c7d9 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6003e06d),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2446722 T3940 C776 P50495 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2446725 T3940 C776 P50495 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7bc2c7d9 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6003e06d),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@7bc2c7d9 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6003e06d),segFN=segments_2,generation=2}
[junit4:junit4] 2> 2446726 T3940 C776 P50495 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 2446727 T3940 C776 P50495 oass.SolrIndexSearcher.<init> Opening Searcher@603ce776 realtime
[junit4:junit4] 2> 2446728 T3940 C776 P50495 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 2446729 T3940 C776 P50495 oasup.LogUpdateProcessor.finish [nodes_used_collection_shard2_replica1] webapp= path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 90
[junit4:junit4] 2> ASYNC NEW_CORE C777 name=nodes_used_collection_shard2_replica2 org.apache.solr.core.SolrCore@39ef8678 url=http://127.0.0.1:50501/nodes_used_collection_shard2_replica2 node=127.0.0.1:50501_ C777_STATE=coll:nodes_used_collection core:nodes_used_collection_shard2_replica2 props:{shard=shard2, state=recovering, core=nodes_used_collection_shard2_replica2, collection=nodes_used_collection, node_name=127.0.0.1:50501_, base_url=http://127.0.0.1:50501}
[junit4:junit4] 2> 2446731 T3998 C777 P50501 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 2446731 T3998 C777 P50501 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 2446737 T3999 C775 P50504 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 2446738 T3999 C775 P50504 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2446741 T3939 C776 P50495 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 2446742 T3939 C776 P50495 oasc.SolrCore.execute [nodes_used_collection_shard2_replica1] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=4
[junit4:junit4] 2> 2446747 T3998 C777 P50501 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 2446748 T3998 C777 P50501 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 2446750 T3998 C777 P50501 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 2446762 T3999 C775 P50504 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@25e0b376 lockFactory=org.apache.lucene.store.NativeFSLockFactory@156ddeb8),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@25e0b376 lockFactory=org.apache.lucene.store.NativeFSLockFactory@156ddeb8),segFN=segments_2,generation=2}
[junit4:junit4] 2> 2446763 T3999 C775 P50504 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 2446764 T3999 C775 P50504 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 2446778 T3999 C775 P50504 oass.SolrIndexSearcher.<init> Opening Searcher@2b6b4a68 main
[junit4:junit4] 2> 2446785 T3994 oasc.SolrCore.registerSearcher [nodes_used_collection_shard1_replica1] Registered new searcher Searcher@2b6b4a68 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 2446787 T3999 C775 P50504 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369732138307/nodes_used_collection_shard1_replica1/data/index.20130528020914429 [CachedDir<<refCount=0;path=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369732138307/nodes_used_collection_shard1_replica1/data/index.20130528020914429;done=true>>]
[junit4:junit4] 2> 2446790 T3999 C775 P50504 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369732138307/nodes_used_collection_shard1_replica1/data/index.20130528020914429
[junit4:junit4] 2> 2446788 T3935 C776 P50495 oasc.SolrCore.execute [nodes_used_collection_shard2_replica1] webapp= path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=21
[junit4:junit4] 2> 2446798 T3998 C777 P50501 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 2446794 T3999 C775 P50504 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369732138307/nodes_used_collection_shard1_replica1/data/index.20130528020914429
[junit4:junit4] 2> 2446799 T3999 C775 P50504 oasc.RecoveryStrategy.replay No replay needed. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2446802 T3999 C775 P50504 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2446803 T3999 C775 P50504 oasc.ZkController.publish publishing core=nodes_used_collection_shard1_replica1 state=active
[junit4:junit4] 2> 2446805 T3998 C777 P50501 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-1369732135468/nodes_used_collection_shard2_replica2/data/index.20130528020914602
[junit4:junit4] 2> 2446805 T3998 C777 P50501 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@33b5fda9 lockFactory=org.apache.lucene.store.NativeFSLockFactory@76934284) fullCopy=false
[junit4:junit4] 2> 2446812 T3999 C775 P50504 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=nodes_used_collection_shard1_replica1
[junit4:junit4] 2> 2446812 T3940 C776 P50495 oasc.SolrCore.execute [nodes_used_collection_shard2_replica1] webapp= path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=1
[junit4:junit4] 2> 2446835 T3998 C777 P50501 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 2446901 T3998 C777 P50501 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 2446901 T3998 C777 P50501 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 2446905 T3998 C777 P50501 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@f22bd6b lockFactory=org.apache.lucene.store.NativeFSLockFactory@4e2c3df2),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@f22bd6b lockFactory=org.apache.lucene.store.NativeFSLockFactory@4e2c3df2),segFN=segments_2,generation=2}
[junit4:junit4] 2> 2446907 T3998 C777 P50501 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 2446908 T3998 C777 P50501 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 2446908 T3998 C777 P50501 oass.SolrIndexSearcher.<init> Opening Searcher@573fa9cd main
[junit4:junit4] 2> 2446910 T3995 oasc.SolrCore.registerSearcher [nodes_used_collection_shard2_replica2] Registered new searcher Searcher@573fa9cd main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 2446911 T3998 C777 P50501 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-jetty3-1369732135468/nodes_used_collection_shard2_replica2/data/index.20130528020914602 [CachedDir<<refCount=0;path=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369732135468/nodes_used_collection_shard2_replica2/data/index.20130528020914602;done=true>>]
[junit4:junit4] 2> 2446911 T3998 C777 P50501 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-jetty3-1369732135468/nodes_used_collection_shard2_replica2/data/index.20130528020914602
[junit4:junit4] 2> 2446912 T3998 C777 P50501 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-jetty3-1369732135468/nodes_used_collection_shard2_replica2/data/index.20130528020914602
[junit4:junit4] 2> 2446912 T3998 C777 P50501 oasc.RecoveryStrategy.replay No replay needed. core=nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 2446912 T3998 C777 P50501 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 2446912 T3998 C777 P50501 oasc.ZkController.publish publishing core=nodes_used_collection_shard2_replica2 state=active
[junit4:junit4] 2> 2446919 T3998 C777 P50501 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=nodes_used_collection_shard2_replica2
[junit4:junit4] 2> 2447059 T3927 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2447069 T3927 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:50504__nodes_used_collection_shard1_replica1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"nodes_used_collection_shard1_replica1",
[junit4:junit4] 2> "collection":"nodes_used_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:50504_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50504"}
[junit4:junit4] 2> 2447091 T3927 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:50501__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:50501_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50501"}
[junit4:junit4] 2> 2447118 T3926 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> 2447118 T3931 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> 2447119 T4003 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> 2447120 T3972 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> 2447122 T3958 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> 2447122 T4001 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> 2447124 T3986 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> 2447125 T3944 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> 2448756 T3922 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2448781 T3922 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2448787 T3922 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2448841 T3964 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2448859 T3964 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2448923 T3964 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2448998 T3922 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2449012 T3966 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2449020 T3922 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2449086 T3922 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2449101 T3966 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2449114 T3922 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2449116 T3922 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2449117 T3922 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2449134 T3922 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2449134 T3922 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2449135 T3922 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2449136 T3922 oasc.SolrCore.<init> [awholynewcollection_0_shard1_replica4] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369732129298/awholynewcollection_0_shard1_replica4/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369732129298/awholynewcollection_0_shard1_replica4/data/
[junit4:junit4] 2> 2449136 T3922 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4d3f83b5
[junit4:junit4] 2> 2449137 T3922 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2449138 T3922 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-1369732129298/awholynewcollection_0_shard1_replica4/data
[junit4:junit4] 2> 2449139 T3922 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-1369732129298/awholynewcollection_0_shard1_replica4/data/index/
[junit4:junit4] 2> 2449139 T3922 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard1_replica4] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1369732129298/awholynewcollection_0_shard1_replica4/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2449158 T3922 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-1369732129298/awholynewcollection_0_shard1_replica4/data/index
[junit4:junit4] 2> 2449200 T3922 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2e835760 lockFactory=org.apache.lucene.store.NativeFSLockFactory@44ced07e),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2449201 T3922 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2449206 T3922 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2449206 T3922 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2449207 T3922 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2449208 T3922 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2449200 T3966 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2449210 T3922 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2449215 T3922 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2449200 T3964 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2449216 T3922 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2449218 T3922 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2449219 T3922 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2449253 T3922 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2449270 T3964 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2449280 T3982 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2449303 T3964 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2449312 T3982 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2449332 T3952 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2449337 T3964 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2449338 T3964 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2449338 T3964 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2449339 T3922 oass.SolrIndexSearcher.<init> Opening Searcher@513b7082 main
[junit4:junit4] 2> 2449340 T3922 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-1369732129298/awholynewcollection_0_shard1_replica4/data/tlog
[junit4:junit4] 2> 2449350 T3952 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2449356 T3952 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2449357 T3964 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2449358 T3964 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2449359 T3964 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2449360 T3964 oasc.SolrCore.<init> [awholynewcollection_0_shard1_replica1] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369732135468/awholynewcollection_0_shard1_replica1/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369732135468/awholynewcollection_0_shard1_replica1/data/
[junit4:junit4] 2> 2449361 T3964 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4d3f83b5
[junit4:junit4] 2> 2449362 T3964 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2449363 T3964 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-1369732135468/awholynewcollection_0_shard1_replica1/data
[junit4:junit4] 2> 2449364 T3964 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-1369732135468/awholynewcollection_0_shard1_replica1/data/index/
[junit4:junit4] 2> 2449364 T3964 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard1_replica1] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369732135468/awholynewcollection_0_shard1_replica1/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2449369 T3982 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2449374 T3922 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2449375 T3922 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2449379 T3964 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-1369732135468/awholynewcollection_0_shard1_replica1/data/index
[junit4:junit4] 2> 2449381 T4012 oasc.SolrCore.registerSearcher [awholynewcollection_0_shard1_replica4] Registered new searcher Searcher@513b7082 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2449385 T3922 oasc.ZkController.publish publishing core=awholynewcollection_0_shard1_replica4 state=down
[junit4:junit4] 2> 2449412 T3964 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@44eb59ef lockFactory=org.apache.lucene.store.NativeFSLockFactory@5eb8e65b),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2449413 T3964 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2449431 T3964 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2449432 T3964 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2449433 T3964 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2449434 T3964 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2449435 T3964 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2449436 T3964 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2449436 T3964 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2449443 T3964 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2449444 T3964 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2449445 T3953 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2449448 T3966 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2449475 T3936 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2449498 T3953 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2449499 T3964 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2449506 T3953 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2449511 T3966 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2449526 T3936 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2449538 T3966 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2449550 T3966 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2449552 T3966 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2449552 T3966 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2449565 T3936 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2449565 T3964 oass.SolrIndexSearcher.<init> Opening Searcher@3d527f67 main
[junit4:junit4] 2> 2449569 T3964 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-1369732135468/awholynewcollection_0_shard1_replica1/data/tlog
[junit4:junit4] 2> 2449571 T3964 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2449571 T3937 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 2449571 T3964 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2449580 T3966 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2449583 T3966 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2449584 T3966 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2449585 T3966 oasc.SolrCore.<init> [awholynewcollection_0_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-1369732135468/awholynewcollection_0_shard2_replica2/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1369732135468/awholynewcollection_0_shard2_replica2/data/
[junit4:junit4] 2> 2449585 T3966 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4d3f83b5
[junit4:junit4] 2> 2449586 T3966 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2449587 T3966 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-1369732135468/awholynewcollection_0_shard2_replica2/data
[junit4:junit4] 2> 2449588 T3966 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-1369732135468/awholynewcollection_0_shard2_replica2/data/index/
[junit4:junit4] 2> 2449588 T3966 oasc.SolrCore.initIndex WARN [awholynewcollection_0_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-1369732135468/awholynewcollection_0_shard2_replica2/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2449591 T4013 oasc.SolrCore.registerSearcher [awholynewcollection_0_shard1_replica1] Registered new searcher Searcher@3d527f67 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2449594 T3964 oasc.ZkController.publish publishing core=awholynewcollection_0_shard1_replica1 state=down
[junit4:junit4] 2> 2449600 T3966 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-1369732135468/awholynewcollection_0_shard2_replica2/data/index
[junit4:junit4] 2> 2449619 T3982 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2449622 T3952 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2449631 T3937 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2449634 T3982 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2449636 T3937 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2449646 T3966 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@136450dc lockFactory=org.apache.lucene.store.NativeFSLockFactory@6eb0766d),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2449653 T3966 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2449658 T3952 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2449677 T3966 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2449678 T3966 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2449679 T3966 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2449680 T3966 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2449681 T3966 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2449682 T3966 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2449683 T3966 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2449702 T3952 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2449685 T3982 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2449711 T3966 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2449712 T3966 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2449716 T3952 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2449717 T3952 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2449718 T3952 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2449725 T3982 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2449728 T3982 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2449729 T3982 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2449728 T3953 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2449767 T3952 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2449769 T3952 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2449769 T3952 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2449770 T3952 oasc.SolrCore.<init> [awholynewcollection_0_shard1_replica3] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369732133159/awholynewcollection_0_shard1_replica3/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369732133159/awholynewcollection_0_shard1_replica3/data/
[junit4:junit4] 2> 2449770 T3952 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4d3f83b5
[junit4:junit4] 2> 2449771 T3952 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2449772 T3952 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369732133159/awholynewcollection_0_shard1_replica3/data
[junit4:junit4] 2> 2449773 T3952 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369732133159/awholynewcollection_0_shard1_replica3/data/index/
[junit4:junit4] 2> 2449773 T3952 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard1_replica3] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369732133159/awholynewcollection_0_shard1_replica3/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2449774 T3966 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2449781 T3952 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369732133159/awholynewcollection_0_shard1_replica3/data/index
[junit4:junit4] 2> 2449790 T3953 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2449792 T3982 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2449793 T3982 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2449794 T3982 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2449798 T3982 oasc.SolrCore.<init> [awholynewcollection_0_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-jetty4-1369732138307/awholynewcollection_0_shard2_replica1/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1369732138307/awholynewcollection_0_shard2_replica1/data/
[junit4:junit4] 2> 2449798 T3982 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4d3f83b5
[junit4:junit4] 2> 2449799 T3982 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2449800 T3982 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-1369732138307/awholynewcollection_0_shard2_replica1/data
[junit4:junit4] 2> 2449801 T3982 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-1369732138307/awholynewcollection_0_shard2_replica1/data/index/
[junit4:junit4] 2> 2449801 T3982 oasc.SolrCore.initIndex WARN [awholynewcollection_0_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-jetty4-1369732138307/awholynewcollection_0_shard2_replica1/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2449802 T3966 oass.SolrIndexSearcher.<init> Opening Searcher@85a7955 main
[junit4:junit4] 2> 2449803 T3966 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-1369732135468/awholynewcollection_0_shard2_replica2/data/tlog
[junit4:junit4] 2> 2449805 T3953 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2449802 T3952 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@16936764 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3bee1080),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2449808 T3952 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2449817 T3982 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-1369732138307/awholynewcollection_0_shard2_replica1/data/index
[junit4:junit4] 2> 2449817 T3953 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2449819 T3953 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2449819 T3953 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 2449822 T3966 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2449822 T3966 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2449817 T3936 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2449828 T3952 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2449844 T3953 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 2449845 T3953 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 2449845 T3953 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2449846 T3953 oasc.SolrCore.<init> [awholynewcollection_0_shard2_replica4] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369732133159/awholynewcollection_0_shard2_replica4/, dataDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369732133159/awholynewcollection_0_shard2_replica4/data/
[junit4:junit4] 2> 2449846 T3953 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4d3f83b5
[junit4:junit4] 2> 2449847 T3953 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2449844 T3952 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2449848 T3953 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369732133159/awholynewcollection_0_shard2_replica4/data
[junit4:junit4] 2> 2449849 T3953 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369732133159/awholynewcollection_0_shard2_replica4/data/index/
[junit4:junit4] 2> 2449850 T3953 oasc.SolrCore.initIndex WARN [awholynewcollection_0_shard2_replica4] Solr index directory '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369732133159/awholynewcollection_0_shard2_replica4/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2449849 T3952 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2449852 T3952 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2449852 T3952 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2449853 T3952 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2449853 T3952 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2449854 T3952 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2449854 T3952 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2449861 T3953 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1369732133159/awholynewcollection_0_shard2_replica4/data/index
[junit4:junit4] 2> 2449874 T3952 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2449876 T3982 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6bd3bfbb lockFactory=org.apache.lucene.store.NativeFSLockFactory@2b75b3a7),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2449877 T3982 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2449878 T4014 oasc.SolrCore.registerSearcher [awholynewcollection_0_shard2_replica2] Registered new searcher Searcher@85a7955 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2449883 T3966 oasc.ZkController.publish publishing core=awholynewcollection_0_shard2_replica2 state=down
[junit4:junit4] 2> 2449893 T3982 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2449894 T3982 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2449894 T3982 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2449895 T3936 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2449895 T3982 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2449897 T3982 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2449897 T3982 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2449898 T3982 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2449899 T3982 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2449900 T3982 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2449906 T3953 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@29a6b61c lockFactory=org.apache.lucene.store.NativeFSLockFactory@6a3b6a54),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2449906 T3953 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2449924 T3953 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChai
[...truncated too long message...]
ryFactory.close Closing directory: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00001_core/data
[junit4:junit4] 2> 2903331 T4372 oasc.SolrCore.close [00014_core] CLOSING SolrCore org.apache.solr.core.SolrCore@15a020d0
[junit4:junit4] 2> 2903339 T4372 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=5,autocommits=0,soft autocommits=5,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=296,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=296,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 2903341 T4372 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 2903344 T4372 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 2903344 T4372 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> ASYNC NEW_CORE C1215 name=00014_core org.apache.solr.core.SolrCore@15a020d0
[junit4:junit4] 2> 2903513 T4372 C1215 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00014_core/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@65b3fefe),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00014_core/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@65b3fefe),segFN=segments_2,generation=2}
[junit4:junit4] 2> 2903516 T4372 C1215 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 2903743 T4372 oasc.SolrCore.closeSearcher [00014_core] Closing main searcher on request.
[junit4:junit4] 2> 2903981 T4372 oasc.CachingDirectoryFactory.close Closing MockFSDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 2903982 T4372 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00014_core/data/index [CachedDir<<refCount=0;path=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00014_core/data/index;done=false>>]
[junit4:junit4] 2> 2903983 T4372 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00014_core/data/index
[junit4:junit4] 2> 2904076 T4372 oasc.CachingDirectoryFactory.closeCacheValue looking to close /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00014_core/data [CachedDir<<refCount=0;path=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00014_core/data;done=false>>]
[junit4:junit4] 2> 2904078 T4372 oasc.CachingDirectoryFactory.close Closing directory: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/OpenCloseCoreStressTest_/00014_core/data
[junit4:junit4] 2> 2904079 T4372 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4:junit4] 2> 2905920 T4372 oas.SolrTestCaseJ4.tearDown ###Ending test30SecondsNew
[junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=OpenCloseCoreStressTest -Dtests.method=test30SecondsNew -Dtests.seed=BCE488C1890531AE -Dtests.slow=true -Dtests.locale=ar_SD -Dtests.timezone=America/Aruba -Dtests.file.encoding=US-ASCII
[junit4:junit4] FAILURE 52.4s | OpenCloseCoreStressTest.test30SecondsNew <<<
[junit4:junit4] > Throwable #1: java.lang.AssertionError: Core 00000_core bad! expected:<291> but was:<253>
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([BCE488C1890531AE:D8519415DBC5C8EB]:0)
[junit4:junit4] > at org.apache.solr.core.OpenCloseCoreStressTest.checkResults(OpenCloseCoreStressTest.java:304)
[junit4:junit4] > at org.apache.solr.core.OpenCloseCoreStressTest.doStress(OpenCloseCoreStressTest.java:201)
[junit4:junit4] > at org.apache.solr.core.OpenCloseCoreStressTest.test30SecondsNew(OpenCloseCoreStressTest.java:121)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] IGNOR/A 0.00s | OpenCloseCoreStressTest.test10MinutesOld
[junit4:junit4] > Assumption #1: 'nightly' test group is disabled (@Nightly)
[junit4:junit4] 2> 2905939 T4372 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> NOTE: test params are: codec=Lucene42: {id=MockVariableIntBlock(baseBlockSize=13), text=Pulsing41(freqCutoff=20 minBlockSize=50 maxBlockSize=152)}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=ar_SD, timezone=America/Aruba
[junit4:junit4] 2> NOTE: Mac OS X 10.8.3 x86_64/Oracle Corporation 1.7.0_21 (64-bit)/cpus=2,threads=1,free=166113592,total=366411776
[junit4:junit4] 2> NOTE: All tests run in this JVM: [TestCoreDiscovery, TestSolrIndexConfig, LukeRequestHandlerTest, SuggesterWFSTTest, ExternalFileFieldSortTest, TestTrie, TestCSVResponseWriter, DirectSolrConnectionTest, RecoveryZkTest, TestFieldTypeCollectionResource, LeaderElectionTest, SolrCmdDistributorTest, AliasIntegrationTest, TestSchemaNameResource, TestDistributedSearch, TestIndexingPerformance, ClusterStateUpdateTest, TestSystemIdResolver, DisMaxRequestHandlerTest, ZkSolrClientTest, UUIDFieldTest, DistanceFunctionTest, TestPropInjectDefaults, TestJoin, SolrIndexConfigTest, HighlighterTest, TestPerFieldSimilarity, TestJmxMonitoredMap, SolrRequestParserTest, SolrTestCaseJ4Test, UpdateParamsTest, TestShardHandlerFactory, SortByFunctionTest, SpellingQueryConverterTest, SOLR749Test, BinaryUpdateRequestHandlerTest, QueryEqualityTest, SchemaVersionSpecificBehaviorTest, QueryParsingTest, TestDefaultSimilarityFactory, OverseerTest, TestIndexSearcher, TestCharFilters, TestSolr4Spatial, CopyFieldTest, IndexSchemaRuntimeFieldTest, DOMUtilTest, XmlUpdateRequestHandlerTest, TestSchemaSimilarityResource, TestRangeQuery, OverseerCollectionProcessorTest, TestElisionMultitermQuery, TestUtils, StatelessScriptUpdateProcessorFactoryTest, TestCodecSupport, ShowFileRequestHandlerTest, DocumentBuilderTest, TestFuzzyAnalyzedSuggestions, SolrCoreTest, AnalysisAfterCoreReloadTest, TestPartialUpdateDeduplication, TestMaxScoreQueryParser, TestFastWriter, TestFaceting, FieldAnalysisRequestHandlerTest, BasicZkTest, TestStressVersions, UnloadDistributedZkTest, DirectSolrSpellCheckerTest, JSONWriterTest, QueryResultKeyTest, SampleTest, TestDistributedGrouping, BasicDistributedZkTest, SyncSliceTest, CoreAdminHandlerTest, TestValueSourceCache, SearchHandlerTest, QueryElevationComponentTest, PrimitiveFieldTypeTest, TestCoreContainer, TestBinaryResponseWriter, TestFoldingMultitermQuery, TestPseudoReturnFields, PingRequestHandlerTest, TestSolrCoreProperties, MinimalSchemaTest, TestLazyCores, CircularListTest, TestBM25SimilarityFactory, TestXIncludeConfig, TestLuceneMatchVersion, OutputWriterTest, ZkCLITest, TestAtomicUpdateErrorCases, ReturnFieldsTest, LeaderElectionIntegrationTest, SynonymTokenizerTest, CSVRequestHandlerTest, TestFiltering, PathHierarchyTokenizerFactoryTest, TestSurroundQueryParser, PolyFieldTest, StatsComponentTest, TestSchemaResource, TestUpdate, PreAnalyzedUpdateProcessorTest, TestStressLucene, TestGroupingSearch, TestZkChroot, RAMDirectoryFactoryTest, CoreContainerCoreInitFailuresTest, TestAnalyzedSuggestions, TestSuggestSpellingConverter, BasicDistributedZk2Test, SpellPossibilityIteratorTest, XsltUpdateRequestHandlerTest, TestSolrXml, SpatialFilterTest, SolrIndexSplitterTest, ShardRoutingCustomTest, TestStressRecovery, SignatureUpdateProcessorFactoryTest, IndexSchemaTest, TestMergePolicyConfig, TestReload, DebugComponentTest, DocumentAnalysisRequestHandlerTest, DocValuesMultiTest, TestFastOutputStream, TestSearchPerf, ClusterStateTest, HardAutoCommitTest, TestQueryTypes, TestUniqueKeyFieldResource, TestQuerySenderNoQuery, TestRecovery, TestSolrQueryParserResource, MultiTermTest, FileBasedSpellCheckerTest, FieldMutatingUpdateProcessorTest, ChaosMonkeySafeLeaderTest, CollectionsAPIDistributedZkTest, OpenCloseCoreStressTest]
[junit4:junit4] Completed in 107.44s, 6 tests, 1 failure, 4 skipped <<< FAILURES!
[...truncated 451 lines...]
BUILD FAILED
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/build.xml:380: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/build.xml:360: 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:1240: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:884: There were test failures: 295 suites, 1231 tests, 2 failures, 18 ignored (6 assumptions)
Total time: 114 minutes 11 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-trunk-MacOSX (64bit/jdk1.7.0) - Build # 515 -
Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-MacOSX/515/
Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseParallelGC
All tests passed
Build Log:
[...truncated 9215 lines...]
[junit4:junit4] ERROR: JVM J0 ended with an exception, command line: /Library/Java/JavaVirtualMachines/jdk1.7.0_21.jdk/Contents/Home/jre/bin/java -XX:-UseCompressedOops -XX:+UseParallelGC -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/heapdumps -Dtests.prefix=tests -Dtests.seed=52D426A5AEE165F1 -Xmx512M -Dtests.iters= -Dtests.verbose=false -Dtests.infostream=false -Dtests.codec=random -Dtests.postingsformat=random -Dtests.docvaluesformat=random -Dtests.locale=random -Dtests.timezone=random -Dtests.directory=random -Dtests.linedocsfile=europarl.lines.txt.gz -Dtests.luceneMatchVersion=5.0 -Dtests.cleanthreads=perClass -Djava.util.logging.config.file=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/tools/junit4/logging.properties -Dtests.nightly=false -Dtests.weekly=false -Dtests.slow=true -Dtests.asserts.gracious=false -Dtests.multiplier=1 -DtempDir=. -Djava.io.tmpdir=. -Djunit4.tempDir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/temp -Dclover.db.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/build/clover/db -Djava.security.manager=org.apache.lucene.util.TestSecurityManager -Djava.security.policy=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/tools/junit4/tests.policy -Dlucene.version=5.0-SNAPSHOT -Djetty.testMode=1 -Djetty.insecurerandom=1 -Dsolr.directoryFactory=org.apache.solr.core.MockDirectoryFactory -Djava.awt.headless=true -classpath /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/classes/test:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-test-framework/classes/java:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/build/test-framework/classes/java:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/build/codecs/classes/java:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-solrj/classes/java:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/classes/java:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/build/analysis/common/lucene-analyzers-common-5.0-SNAPSHOT.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/build/analysis/kuromoji/lucene-analyzers-kuromoji-5.0-SNAPSHOT.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/build/analysis/phonetic/lucene-analyzers-phonetic-5.0-SNAPSHOT.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/build/codecs/lucene-codecs-5.0-SNAPSHOT.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/build/highlighter/lucene-highlighter-5.0-SNAPSHOT.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/build/memory/lucene-memory-5.0-SNAPSHOT.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/build/misc/lucene-misc-5.0-SNAPSHOT.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/build/spatial/lucene-spatial-5.0-SNAPSHOT.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/build/suggest/lucene-suggest-5.0-SNAPSHOT.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/build/grouping/lucene-grouping-5.0-SNAPSHOT.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/build/queries/lucene-queries-5.0-SNAPSHOT.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/build/queryparser/lucene-queryparser-5.0-SNAPSHOT.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/core/lib/cglib-nodep-2.2.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/core/lib/commons-cli-1.2.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/core/lib/commons-codec-1.7.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/core/lib/commons-fileupload-1.2.1.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/core/lib/commons-lang-2.6.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/core/lib/easymock-3.0.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/core/lib/guava-14.0.1.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/core/lib/javax.servlet-api-3.0.1.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/core/lib/objenesis-1.2.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/core/lib/org.restlet-2.1.1.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/core/lib/org.restlet.ext.servlet-2.1.1.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/core/lib/spatial4j-0.3.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/solrj/lib/commons-io-2.1.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/solrj/lib/httpclient-4.2.3.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/solrj/lib/httpcore-4.2.2.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/solrj/lib/httpmime-4.2.3.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/solrj/lib/jcl-over-slf4j-1.6.6.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/solrj/lib/jul-to-slf4j-1.6.6.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/solrj/lib/log4j-1.2.16.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/solrj/lib/noggit-0.5.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/solrj/lib/slf4j-api-1.6.6.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/solrj/lib/slf4j-log4j12-1.6.6.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/solrj/lib/wstx-asl-3.2.7.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/solrj/lib/zookeeper-3.4.5.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/example/lib/jetty-continuation-8.1.10.v20130312.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/example/lib/jetty-deploy-8.1.10.v20130312.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/example/lib/jetty-http-8.1.10.v20130312.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/example/lib/jetty-io-8.1.10.v20130312.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/example/lib/jetty-jmx-8.1.10.v20130312.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/example/lib/jetty-security-8.1.10.v20130312.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/example/lib/jetty-server-8.1.10.v20130312.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/example/lib/jetty-servlet-8.1.10.v20130312.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/example/lib/jetty-util-8.1.10.v20130312.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/example/lib/jetty-webapp-8.1.10.v20130312.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/example/lib/jetty-xml-8.1.10.v20130312.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/example/lib/servlet-api-3.0.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/example/example-DIH/solr/db/lib/derby-10.9.1.0.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/example/example-DIH/solr/db/lib/hsqldb-1.8.0.10.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/build/core/classes/java:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/test-framework/lib/junit-4.10.jar:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/test-framework/lib/randomizedtesting-runner-2.0.10.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-launcher.jar:/Users/jenkins/.ant/lib/ivy-2.3.0.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-antlr.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-bcel.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-bsf.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-log4j.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-oro.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-regexp.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-resolver.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-apache-xalan2.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-commons-logging.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-commons-net.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jai.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-javamail.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jdepend.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jmf.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-jsch.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-junit.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-junit4.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-netrexx.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-swing.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant-testutil.jar:/Users/jenkins/jenkins-slave/tools/hudson.tasks.Ant_AntInstallation/ANT_1.8.2/lib/ant.jar:/Library/Java/JavaVirtualMachines/jdk1.7.0_21.jdk/Contents/Home/lib/tools.jar:/Users/jenkins/.ivy2/cache/com.carrotsearch.randomizedtesting/junit4-ant/jars/junit4-ant-2.0.10.jar -ea:org.apache.lucene... -ea:org.apache.solr... com.carrotsearch.ant.tasks.junit4.slave.SlaveMainSafe -flush -eventsfile /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/temp/junit4-J0-20130528_161948_881.events @/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/temp/junit4-J0-20130528_161948_881.suites
[junit4:junit4] ERROR: JVM J0 ended with an exception: Forked process returned with error code: 134. Very likely a JVM crash. Process output piped in logs above.
[junit4:junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4.executeSlave(JUnit4.java:1254)
[junit4:junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4.access$000(JUnit4.java:67)
[junit4:junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4$2.call(JUnit4.java:822)
[junit4:junit4] at com.carrotsearch.ant.tasks.junit4.JUnit4$2.call(JUnit4.java:819)
[junit4:junit4] at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
[junit4:junit4] at java.util.concurrent.FutureTask.run(FutureTask.java:166)
[junit4:junit4] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
[junit4:junit4] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
[junit4:junit4] at java.lang.Thread.run(Thread.java:722)
BUILD FAILED
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/build.xml:380: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/build.xml:360: 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:1240: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:884: At least one slave process threw an exception, first: Forked process returned with error code: 134. Very likely a JVM crash. Process output piped in logs above.
Total time: 59 minutes 21 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure