You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/10/31 23:32:19 UTC
[JENKINS] Lucene-Solr-4.x-MacOSX (64bit/jdk1.7.0) - Build # 943 -
Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-MacOSX/943/
Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseSerialGC
All tests passed
Build Log:
[...truncated 26574 lines...]
-check-forbidden-java-apis:
[forbidden-apis] Reading bundled API signatures: jdk-unsafe-1.6
[forbidden-apis] Reading bundled API signatures: jdk-deprecated-1.6
[forbidden-apis] Reading bundled API signatures: commons-io-unsafe-2.1
[forbidden-apis] Reading API signatures: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/tools/forbiddenApis/base.txt
[forbidden-apis] Reading API signatures: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/tools/forbiddenApis/servlet-api.txt
[forbidden-apis] Loading classes to check...
[forbidden-apis] Scanning for API signatures and dependencies...
[forbidden-apis] WARNING: The referenced class 'org.apache.lucene.collation.ICUCollationKeyAnalyzer' cannot be loaded. Please fix the classpath!
[forbidden-apis] WARNING: The referenced class 'org.apache.lucene.analysis.uima.ae.AEProviderFactory' cannot be loaded. Please fix the classpath!
[forbidden-apis] WARNING: The referenced class 'org.apache.lucene.analysis.uima.ae.AEProviderFactory' cannot be loaded. Please fix the classpath!
[forbidden-apis] WARNING: The referenced class 'org.apache.lucene.analysis.uima.ae.AEProvider' cannot be loaded. Please fix the classpath!
[forbidden-apis] Forbidden method invocation: java.util.concurrent.Executors#newFixedThreadPool(int) [Spawns threads with vague names; use a custom thread factory (Lucene's NamedThreadFactory, Solr's DefaultSolrThreadFactory) and name threads so that you can tell (by its name) which executor it is associated with]
[forbidden-apis] in org.apache.solr.update.TestDocBasedVersionConstraints (TestDocBasedVersionConstraints.java:361)
[forbidden-apis] Scanned 2515 (and 1376 related) class file(s) for forbidden API invocations (in 6.40s), 1 error(s).
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:428: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:67: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build.xml:286: Check for forbidden API calls failed, see log.
Total time: 95 minutes 50 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-4.x-MacOSX (64bit/jdk1.7.0) - Build # 945 -
Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-MacOSX/945/
Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC
1 tests failed.
FAILED: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testDistribSearch
Error Message:
Stack Trace:
java.lang.AssertionError
at __randomizedtesting.SeedInfo.seed([F6239E6FBA765C85:77C51077CD293CB9]:0)
at org.junit.Assert.fail(Assert.java:92)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.junit.Assert.assertTrue(Assert.java:54)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testSolrJAPICalls(CollectionsAPIDistributedZkTest.java:265)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:195)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:744)
Build Log:
[...truncated 10087 lines...]
[junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4] 2> 894245 T1706 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /gl_/ri
[junit4] 2> 894253 T1706 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1383307942103
[junit4] 2> 894254 T1706 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 894256 T1707 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 894357 T1706 oasc.ZkTestServer.run start zk server on port:52402
[junit4] 2> 894358 T1706 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 894364 T1713 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5a0b8133 name:ZooKeeperConnection Watcher:127.0.0.1:52402 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 894365 T1706 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 894365 T1706 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 894379 T1706 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 894383 T1715 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6873f764 name:ZooKeeperConnection Watcher:127.0.0.1:52402/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 894383 T1706 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 894383 T1706 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 894390 T1706 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 894397 T1706 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 894407 T1706 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 894456 T1706 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 894457 T1706 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 894477 T1706 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 894477 T1706 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 894485 T1706 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 894485 T1706 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 894492 T1706 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 894492 T1706 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 894499 T1706 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 894500 T1706 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 894508 T1706 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 894509 T1706 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 894520 T1706 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 894521 T1706 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 894530 T1706 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 894532 T1706 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 894540 T1706 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 894540 T1706 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 894549 T1706 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 894550 T1706 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> Using new style solr.xml
[junit4] 2> 894563 T1706 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 894567 T1717 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@64f04ef3 name:ZooKeeperConnection Watcher:127.0.0.1:52402 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 894568 T1706 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 894568 T1706 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 894578 T1706 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 894583 T1719 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@609d811f name:ZooKeeperConnection Watcher:127.0.0.1:52402/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 894583 T1706 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 894585 T1706 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf2/solrconfig.xml
[junit4] 2> 894585 T1706 oascc.SolrZkClient.makePath makePath: /configs/conf2/solrconfig.xml
[junit4] 2> 894597 T1706 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf2/schema.xml
[junit4] 2> 894598 T1706 oascc.SolrZkClient.makePath makePath: /configs/conf2/schema.xml
[junit4] 2> 894607 T1706 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf2/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 894607 T1706 oascc.SolrZkClient.makePath makePath: /configs/conf2/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 894616 T1706 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf2/stopwords.txt
[junit4] 2> 894617 T1706 oascc.SolrZkClient.makePath makePath: /configs/conf2/stopwords.txt
[junit4] 2> 894626 T1706 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf2/protwords.txt
[junit4] 2> 894627 T1706 oascc.SolrZkClient.makePath makePath: /configs/conf2/protwords.txt
[junit4] 2> 894636 T1706 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf2/currency.xml
[junit4] 2> 894637 T1706 oascc.SolrZkClient.makePath makePath: /configs/conf2/currency.xml
[junit4] 2> 894646 T1706 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf2/open-exchange-rates.json
[junit4] 2> 894647 T1706 oascc.SolrZkClient.makePath makePath: /configs/conf2/open-exchange-rates.json
[junit4] 2> 894655 T1706 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf2/mapping-ISOLatin1Accent.txt
[junit4] 2> 894656 T1706 oascc.SolrZkClient.makePath makePath: /configs/conf2/mapping-ISOLatin1Accent.txt
[junit4] 2> 894666 T1706 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf2/old_synonyms.txt
[junit4] 2> 894667 T1706 oascc.SolrZkClient.makePath makePath: /configs/conf2/old_synonyms.txt
[junit4] 2> 894675 T1706 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf2/synonyms.txt
[junit4] 2> 894675 T1706 oascc.SolrZkClient.makePath makePath: /configs/conf2/synonyms.txt
[junit4] 2> 894685 T1706 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/elevate.xml to /configs/conf2/elevate.xml
[junit4] 2> 894686 T1706 oascc.SolrZkClient.makePath makePath: /configs/conf2/elevate.xml
[junit4] 2> 895109 T1706 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 895118 T1706 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52407
[junit4] 2> 895119 T1706 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 895120 T1706 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 895121 T1706 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1383307942545
[junit4] 2> 895121 T1706 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1383307942545/'
[junit4] 2> 895153 T1706 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1383307942545/solr.xml
[junit4] 2> 895221 T1706 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 895222 T1706 oasc.CoreContainer.<init> New CoreContainer 1299544618
[junit4] 2> 895222 T1706 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1383307942545/]
[junit4] 2> 895223 T1706 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 895224 T1706 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 895224 T1706 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 895224 T1706 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 895224 T1706 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 895225 T1706 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 895225 T1706 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 895225 T1706 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 895226 T1706 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 895230 T1706 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 895230 T1706 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 895231 T1706 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52402/solr
[junit4] 2> 895231 T1706 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 895232 T1706 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 895237 T1730 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@653607c7 name:ZooKeeperConnection Watcher:127.0.0.1:52402 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 895238 T1706 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 895249 T1706 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 895254 T1732 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@337d9531 name:ZooKeeperConnection Watcher:127.0.0.1:52402/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 895254 T1706 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 895259 T1706 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 895269 T1706 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 895281 T1706 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 895287 T1706 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52407_gl_%2Fri
[junit4] 2> 895290 T1706 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52407_gl_%2Fri
[junit4] 2> 895300 T1706 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 895316 T1706 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 895324 T1706 oasc.Overseer.start Overseer (id=90656469294186501-127.0.0.1:52407_gl_%2Fri-n_0000000000) starting
[junit4] 2> 895333 T1706 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 895348 T1734 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 895351 T1706 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 895361 T1706 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 895367 T1706 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 895377 T1733 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 895384 T1706 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1383307942545
[junit4] 2> 895492 T1706 oasc.CorePropertiesLocator.discoverUnder Found core conf in /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1383307942545/conf/
[junit4] 2> 895500 T1706 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 895502 T1706 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 895502 T1706 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 895507 T1706 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 895518 T1737 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4dc49492 name:ZooKeeperConnection Watcher:127.0.0.1:52402/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 895519 T1706 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 895523 T1706 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 895532 T1706 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 895925 T1706 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 895931 T1706 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52411
[junit4] 2> 895932 T1706 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 895932 T1706 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 895933 T1706 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1383307943381
[junit4] 2> 895934 T1706 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1383307943381/'
[junit4] 2> 895966 T1706 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1383307943381/solr.xml
[junit4] 2> 896053 T1706 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 896054 T1706 oasc.CoreContainer.<init> New CoreContainer 1114847790
[junit4] 2> 896054 T1706 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1383307943381/]
[junit4] 2> 896057 T1706 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 896057 T1706 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 896058 T1706 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 896058 T1706 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 896059 T1706 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 896059 T1706 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 896060 T1706 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 896060 T1706 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 896061 T1706 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 896067 T1706 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 896068 T1706 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 896068 T1706 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52402/solr
[junit4] 2> 896069 T1706 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 896071 T1706 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 896075 T1748 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@47daff19 name:ZooKeeperConnection Watcher:127.0.0.1:52402 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 896076 T1706 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 896104 T1706 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 896105 T1750 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@737dde73 name:ZooKeeperConnection Watcher:127.0.0.1:52402/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 896106 T1706 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 896120 T1706 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 897130 T1706 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52411_gl_%2Fri
[junit4] 2> 897132 T1706 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52411_gl_%2Fri
[junit4] 2> 897141 T1732 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 897142 T1737 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 897142 T1750 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 897156 T1706 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1383307943381
[junit4] 2> 897302 T1706 oasc.CorePropertiesLocator.discoverUnder Found core conf in /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1383307943381/conf/
[junit4] 2> 897310 T1706 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 897311 T1706 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 897312 T1706 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 897715 T1706 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 897722 T1706 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52414
[junit4] 2> 897723 T1706 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 897723 T1706 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 897724 T1706 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383307945166
[junit4] 2> 897724 T1706 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383307945166/'
[junit4] 2> 897757 T1706 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383307945166/solr.xml
[junit4] 2> 897863 T1706 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 897864 T1706 oasc.CoreContainer.<init> New CoreContainer 1648874462
[junit4] 2> 897864 T1706 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383307945166/]
[junit4] 2> 897866 T1706 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 897867 T1706 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 897868 T1706 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 897868 T1706 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 897868 T1706 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 897870 T1706 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 897870 T1706 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 897871 T1706 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 897871 T1706 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 897876 T1706 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 897877 T1706 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 897877 T1706 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52402/solr
[junit4] 2> 897878 T1706 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 897880 T1706 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 897885 T1762 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f30a57d name:ZooKeeperConnection Watcher:127.0.0.1:52402 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 897887 T1706 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 897899 T1706 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 897904 T1764 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6e3091c2 name:ZooKeeperConnection Watcher:127.0.0.1:52402/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 897905 T1706 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 897921 T1706 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 898936 T1706 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52414_gl_%2Fri
[junit4] 2> 898939 T1706 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52414_gl_%2Fri
[junit4] 2> 898947 T1737 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 898948 T1750 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 898948 T1764 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 898948 T1732 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 898962 T1706 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383307945166
[junit4] 2> 899102 T1706 oasc.CorePropertiesLocator.discoverUnder Found core conf in /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383307945166/conf/
[junit4] 2> 899109 T1706 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 899110 T1706 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 899110 T1706 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 899430 T1706 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 899435 T1706 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52417
[junit4] 2> 899436 T1706 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 899436 T1706 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 899437 T1706 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383307946963
[junit4] 2> 899437 T1706 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383307946963/'
[junit4] 2> 899467 T1706 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383307946963/solr.xml
[junit4] 2> 899530 T1706 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 899530 T1706 oasc.CoreContainer.<init> New CoreContainer 816089082
[junit4] 2> 899531 T1706 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383307946963/]
[junit4] 2> 899532 T1706 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 899533 T1706 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 899533 T1706 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 899533 T1706 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 899533 T1706 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 899534 T1706 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 899534 T1706 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 899534 T1706 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 899534 T1706 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 899540 T1706 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 899540 T1706 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 899540 T1706 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52402/solr
[junit4] 2> 899540 T1706 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 899542 T1706 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 899547 T1776 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5f4a6dcf name:ZooKeeperConnection Watcher:127.0.0.1:52402 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 899549 T1706 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 899557 T1706 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 899562 T1778 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5e4463aa name:ZooKeeperConnection Watcher:127.0.0.1:52402/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 899563 T1706 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 899575 T1706 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 900585 T1706 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52417_gl_%2Fri
[junit4] 2> 900588 T1706 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52417_gl_%2Fri
[junit4] 2> 900598 T1750 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 900599 T1737 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 900599 T1764 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 900599 T1732 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 900600 T1778 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 900613 T1706 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383307946963
[junit4] 2> 900723 T1706 oasc.CorePropertiesLocator.discoverUnder Found core conf in /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383307946963/conf/
[junit4] 2> 900728 T1706 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 900729 T1706 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 900729 T1706 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 901064 T1706 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 901069 T1706 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52420
[junit4] 2> 901070 T1706 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 901071 T1706 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 901071 T1706 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383307948582
[junit4] 2> 901071 T1706 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383307948582/'
[junit4] 2> 901100 T1706 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383307948582/solr.xml
[junit4] 2> 901166 T1706 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 901166 T1706 oasc.CoreContainer.<init> New CoreContainer 2011154278
[junit4] 2> 901167 T1706 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383307948582/]
[junit4] 2> 901168 T1706 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 901168 T1706 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 901169 T1706 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 901169 T1706 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 901169 T1706 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 901169 T1706 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 901170 T1706 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 901170 T1706 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 901170 T1706 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 901174 T1706 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 901174 T1706 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 901175 T1706 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52402/solr
[junit4] 2> 901175 T1706 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 901177 T1706 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 901181 T1790 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b2666d2 name:ZooKeeperConnection Watcher:127.0.0.1:52402 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 901182 T1706 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 901189 T1706 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 901193 T1792 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@711489d3 name:ZooKeeperConnection Watcher:127.0.0.1:52402/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 901194 T1706 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 901205 T1706 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 902217 T1706 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52420_gl_%2Fri
[junit4] 2> 902220 T1706 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52420_gl_%2Fri
[junit4] 2> 902231 T1750 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 902232 T1764 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 902232 T1732 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 902232 T1792 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 902233 T1778 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 902234 T1737 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 902244 T1706 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383307948582
[junit4] 2> 902364 T1706 oasc.CorePropertiesLocator.discoverUnder Found core conf in /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383307948582/conf/
[junit4] 2> 902371 T1706 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 902373 T1706 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 902373 T1706 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 902471 T1745 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=2&collection.configName=conf1&name=solrj_collection&replicationFactor=2&action=CREATE&router.field=myOwnField&wt=javabin&router.name=compositeId&version=2
[junit4] 2> 902476 T1732 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4] 2> 902481 T1734 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000000 message:{
[junit4] 2> "operation":"createcollection",
[junit4] 2> "fromApi":"true",
[junit4] 2> "name":"solrj_collection",
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "collection.configName":"conf1",
[junit4] 2> "numShards":"2",
[junit4] 2> "router.field":"myOwnField",
[junit4] 2> "router.name":"compositeId"}
[junit4] 2> 902481 T1734 oasc.OverseerCollectionProcessor.processMessage WARN OverseerCollectionProcessor.processMessage : createcollection , {
[junit4] 2> "operation":"createcollection",
[junit4] 2> "fromApi":"true",
[junit4] 2> "name":"solrj_collection",
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "collection.configName":"conf1",
[junit4] 2> "numShards":"2",
[junit4] 2> "router.field":"myOwnField",
[junit4] 2> "router.name":"compositeId"}
[junit4] 2> 902921 T1733 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 902924 T1733 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: solrj_collection
[junit4] 2> 902924 T1733 oasc.Overseer$ClusterStateUpdater.createCollection Create collection solrj_collection with shards [shard1, shard2]
[junit4] 2> 902936 T1778 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 902936 T1732 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 902937 T1764 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 902937 T1792 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 902937 T1737 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 902937 T1750 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 902995 T1734 oasc.OverseerCollectionProcessor.createCollection going to create cores replicas shardNames [shard1, shard2] , repFactor : 2
[junit4] 2> 902996 T1734 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica1 as part of slice shard1 of collection solrj_collection on 127.0.0.1:52414_gl_%2Fri
[junit4] 2> 902997 T1734 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica2 as part of slice shard1 of collection solrj_collection on 127.0.0.1:52411_gl_%2Fri
[junit4] 2> 902998 T1734 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica1 as part of slice shard2 of collection solrj_collection on 127.0.0.1:52417_gl_%2Fri
[junit4] 2> 903001 T1734 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica2 as part of slice shard2 of collection solrj_collection on 127.0.0.1:52407_gl_%2Fri
[junit4] 2> 903961 T1743 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica2 state=down
[junit4] 2> 903961 T1774 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica1 state=down
[junit4] 2> 903962 T1726 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica2 state=down
[junit4] 2> 903964 T1758 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica1 state=down
[junit4] 2> 903966 T1743 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 903967 T1774 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 903967 T1758 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 903967 T1726 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 904455 T1733 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 904457 T1733 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:52411/gl_/ri",
[junit4] 2> "core":"solrj_collection_shard1_replica2",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52411_gl_%2Fri",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"solrj_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 904468 T1733 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:52417/gl_/ri",
[junit4] 2> "core":"solrj_collection_shard2_replica1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52417_gl_%2Fri",
[junit4] 2> "shard":"shard2",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"solrj_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 904478 T1733 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:52407/gl_/ri",
[junit4] 2> "core":"solrj_collection_shard2_replica2",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52407_gl_%2Fri",
[junit4] 2> "shard":"shard2",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"solrj_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 904490 T1733 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:52414/gl_/ri",
[junit4] 2> "core":"solrj_collection_shard1_replica1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52414_gl_%2Fri",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"solrj_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 904503 T1764 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 904503 T1732 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 904503 T1737 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 904503 T1778 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 904503 T1792 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 904503 T1750 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 904969 T1743 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica2
[junit4] 2> 904969 T1758 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica1
[junit4] 2> 904972 T1743 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica2' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1383307943381/solrj_collection_shard1_replica2
[junit4] 2> 904973 T1743 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
[junit4] 2> 904969 T1726 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica2
[junit4] 2> 904969 T1774 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica1
[junit4] 2> 904977 T1726 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica2' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1383307942545/solrj_collection_shard2_replica2
[junit4] 2> 904977 T1726 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
[junit4] 2> 904973 T1758 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica1' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383307945166/solrj_collection_shard1_replica1
[junit4] 2> 904978 T1758 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
[junit4] 2> 904981 T1774 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica1' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383307946963/solrj_collection_shard2_replica1
[junit4] 2> 904982 T1774 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
[junit4] 2> 904982 T1758 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:solrj_collection
[junit4] 2> 904983 T1758 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection
[junit4] 2> 904985 T1743 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:solrj_collection
[junit4] 2> 904982 T1726 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:solrj_collection
[junit4] 2> 904985 T1774 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:solrj_collection
[junit4] 2> 904986 T1774 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection
[junit4] 2> 904985 T1743 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection
[junit4] 2> 904986 T1726 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection
[junit4] 2> 904993 T1774 oasc.ZkController.readConfigName Load collection config from:/collections/solrj_collection
[junit4] 2> 904995 T1758 oasc.ZkController.readConfigName Load collection config from:/collections/solrj_collection
[junit4] 2> 904998 T1743 oasc.ZkController.readConfigName Load collection config from:/collections/solrj_collection
[junit4] 2> 904998 T1726 oasc.ZkController.readConfigName Load collection config from:/collections/solrj_collection
[junit4] 2> 905000 T1774 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383307946963/solrj_collection_shard2_replica1/'
[junit4] 2> 905002 T1743 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1383307943381/solrj_collection_shard1_replica2/'
[junit4] 2> 905003 T1758 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383307945166/solrj_collection_shard1_replica1/'
[junit4] 2> 905006 T1726 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1383307942545/solrj_collection_shard2_replica2/'
[junit4] 2> 905173 T1726 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 905192 T1743 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 905224 T1758 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 905226 T1774 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 905301 T1743 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 905309 T1743 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 905327 T1743 oass.IndexSchema.readSchema [solrj_collection_shard1_replica2] Schema name=test
[junit4] 2> 905351 T1774 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 905363 T1774 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 905370 T1758 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 905380 T1774 oass.IndexSchema.readSchema [solrj_collection_shard2_replica1] Schema name=test
[junit4] 2> 905393 T1758 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 905396 T1726 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 905408 T1758 oass.IndexSchema.readSchema [solrj_collection_shard1_replica1] Schema name=test
[junit4] 2> 905427 T1726 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 905444 T1726 oass.IndexSchema.readSchema [solrj_collection_shard2_replica2] Schema name=test
[junit4] 2> 907063 T1758 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 907105 T1758 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 907107 T1758 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 907171 T1758 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 907197 T1758 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 907204 T1743 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 907228 T1743 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 907229 T1743 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 907248 T1743 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 907255 T1743 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 907279 T1774 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 907279 T1774 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 907280 T1774 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 907286 T1726 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 907288 T1726 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 907289 T1726 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 907293 T1774 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 907305 T1774 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 907314 T1726 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 907320 T1726 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 907348 T1758 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 907368 T1758 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 907378 T1758 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 907382 T1743 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 907386 T1758 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 907386 T1758 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 907387 T1758 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 907394 T1758 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 907395 T1758 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 907399 T1758 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 907400 T1758 oasc.SolrCore.<init> [solrj_collection_shard1_replica1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383307945166/solrj_collection_shard1_replica1/, dataDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383307945166/solrj_collection_shard1_replica1/data/
[junit4] 2> 907401 T1758 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2b1cbbd3
[junit4] 2> 907407 T1743 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 907409 T1758 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383307945166/solrj_collection_shard1_replica1/data
[junit4] 2> 907409 T1758 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383307945166/solrj_collection_shard1_replica1/data/index/
[junit4] 2> 907409 T1758 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica1] Solr index directory '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383307945166/solrj_collection_shard1_replica1/data/index' doesn't exist. Creating new index...
[junit4] 2> 907410 T1758 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383307945166/solrj_collection_shard1_replica1/data/index
[junit4] 2> 907410 T1758 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=28, maxMergeAtOnceExplicit=11, maxMergedSegmentMB=52.9638671875, floorSegmentMB=0.6357421875, forceMergeDeletesPctAllowed=6.813756789965147, segmentsPerTier=48.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5073531838128024
[junit4] 2> 907411 T1758 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@385f10b1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@20eb4297),segFN=segments_1,generation=1}
[junit4] 2> 907412 T1758 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 907418 T1758 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 907419 T1758 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 907421 T1758 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 907422 T1758 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 907422 T1758 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 907423 T1758 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 907431 T1743 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 907436 T1758 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 907437 T1758 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 907438 T1758 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 907439 T1758 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 907440 T1758 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 907440 T1758 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 907442 T1758 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 907442 T1743 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 907443 T1743 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 907447 T1743 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 907442 T1726 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 907446 T1774 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 907443 T1758 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 907450 T1758 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 907461 T1726 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 907470 T1758 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 907474 T1743 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 907475 T1743 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 907476 T1743 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 907476 T1743 oasc.SolrCore.<init> [solrj_collection_shard1_replica2] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1383307943381/solrj_collection_shard1_replica2/, dataDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1383307943381/solrj_collection_shard1_replica2/data/
[junit4] 2> 907476 T1743 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2b1cbbd3
[junit4] 2> 907484 T1774 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 907498 T1726 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 907507 T1726 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 907507 T1726 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 907508 T1726 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 907509 T1743 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1383307943381/solrj_collection_shard1_replica2/data
[junit4] 2> 907510 T1743 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1383307943381/solrj_collection_shard1_replica2/data/index/
[junit4] 2> 907510 T1743 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica2] Solr index directory '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1383307943381/solrj_collection_shard1_replica2/data/index' doesn't exist. Creating new index...
[junit4] 2> 907511 T1743 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1383307943381/solrj_collection_shard1_replica2/data/index
[junit4] 2> 907511 T1743 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=28, maxMergeAtOnceExplicit=11, maxMergedSegmentMB=52.9638671875, floorSegmentMB=0.6357421875, forceMergeDeletesPctAllowed=6.813756789965147, segmentsPerTier=48.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5073531838128024
[junit4] 2> 907516 T1774 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 907522 T1774 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 907522 T1774 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 907522 T1774 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 907524 T1726 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 907525 T1726 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 907525 T1726 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 907525 T1726 oasc.SolrCore.<init> [solrj_collection_shard2_replica2] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1383307942545/solrj_collection_shard2_replica2/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1383307942545/solrj_collection_shard2_replica2/data/
[junit4] 2> 907526 T1726 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2b1cbbd3
[junit4] 2> 907528 T1758 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 907528 T1758 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 907542 T1726 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1383307942545/solrj_collection_shard2_replica2/data
[junit4] 2> 907543 T1743 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@d24348f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3327a424),segFN=segments_1,generation=1}
[junit4] 2> 907544 T1743 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 907544 T1726 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1383307942545/solrj_collection_shard2_replica2/data/index/
[junit4] 2> 907545 T1726 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica2] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1383307942545/solrj_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
[junit4] 2> 907546 T1726 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1383307942545/solrj_collection_shard2_replica2/data/index
[junit4] 2> 907546 T1726 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=28, maxMergeAtOnceExplicit=11, maxMergedSegmentMB=52.9638671875, floorSegmentMB=0.6357421875, forceMergeDeletesPctAllowed=6.813756789965147, segmentsPerTier=48.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5073531838128024
[junit4] 2> 907554 T1774 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 907555 T1774 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 907556 T1774 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 907557 T1774 oasc.SolrCore.<init> [solrj_collection_shard2_replica1] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383307946963/solrj_collection_shard2_replica1/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383307946963/solrj_collection_shard2_replica1/data/
[junit4] 2> 907557 T1774 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2b1cbbd3
[junit4] 2> 907555 T1743 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 907560 T1758 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=21, maxMergeAtOnceExplicit=44, maxMergedSegmentMB=37.916015625, floorSegmentMB=1.025390625, forceMergeDeletesPctAllowed=4.243424281672431, segmentsPerTier=35.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 907560 T1743 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 907562 T1743 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 907562 T1743 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 907563 T1743 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 907564 T1743 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 907565 T1743 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 907565 T1743 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 907566 T1743 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 907567 T1743 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 907568 T1743 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 907569 T1743 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 907569 T1743 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 907570 T1726 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@145d55f0 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@76ce51d4),segFN=segments_1,generation=1}
[junit4] 2> 907571 T1726 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 907578 T1726 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 907579 T1726 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 907579 T1726 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 907580 T1726 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 907581 T1726 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 907581 T1726 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 907582 T1726 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 907583 T1726 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 907583 T1726 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 907569 T1774 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383307946963/solrj_collection_shard2_replica1/data
[junit4] 2> 907585 T1726 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 907585 T1726 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 907586 T1726 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 907586 T1726 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 907581 T1758 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@385f10b1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@20eb4297),segFN=segments_1,generation=1}
[junit4] 2> 907588 T1774 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383307946963/solrj_collection_shard2_replica1/data/index/
[junit4] 2> 907589 T1774 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica1] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383307946963/solrj_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
[junit4] 2> 907589 T1774 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383307946963/solrj_collection_shard2_replica1/data/index
[junit4] 2> 907590 T1774 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=28, maxMergeAtOnceExplicit=11, maxMergedSegmentMB=52.9638671875, floorSegmentMB=0.6357421875, forceMergeDeletesPctAllowed=6.813756789965147, segmentsPerTier=48.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5073531838128024
[junit4] 2> 907590 T1774 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@44eeab33 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7ee04cef),segFN=segments_1,generation=1}
[junit4] 2> 907591 T1774 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 907570 T1743 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 907595 T1743 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 907596 T1774 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 907597 T1774 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 907597 T1774 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 907598 T1774 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 907598 T1774 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 907599 T1774 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 907600 T1774 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 907600 T1774 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 907600 T1774 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 907601 T1774 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 907602 T1774 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 907602 T1774 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 907588 T1758 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 907603 T1758 oass.SolrIndexSearcher.<init> Opening Searcher@562c5c1e main
[junit4] 2> 907588 T1726 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 907603 T1774 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 907598 T1743 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 907607 T1774 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 907608 T1774 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 907611 T1774 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 907606 T1726 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 907617 T1726 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 907620 T1798 oasc.SolrCore.registerSearcher [solrj_collection_shard1_replica1] Registered new searcher Searcher@562c5c1e main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 907624 T1774 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 907625 T1774 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 907627 T1743 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 907627 T1743 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 907628 T1758 oasc.CoreContainer.registerCore registering core: solrj_collection_shard1_replica1
[junit4] 2> 907628 T1758 oasc.ZkController.register Register replica - core:solrj_collection_shard1_replica1 address:http://127.0.0.1:52414/gl_/ri collection:solrj_collection shard:shard1
[junit4] 2> 907636 T1726 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 907637 T1726 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 907638 T1758 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard1/election
[junit4] 2> 907638 T1774 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=21, maxMergeAtOnceExplicit=44, maxMergedSegmentMB=37.916015625, floorSegmentMB=1.025390625, forceMergeDeletesPctAllowed=4.243424281672431, segmentsPerTier=35.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 907639 T1774 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@44eeab33 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7ee04cef),segFN=segments_1,generation=1}
[junit4] 2> 907640 T1774 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 907640 T1726 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=21, maxMergeAtOnceExplicit=44, maxMergedSegmentMB=37.916015625, floorSegmentMB=1.025390625, forceMergeDeletesPctAllowed=4.243424281672431, segmentsPerTier=35.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 907640 T1743 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=21, maxMergeAtOnceExplicit=44, maxMergedSegmentMB=37.916015625, floorSegmentMB=1.025390625, forceMergeDeletesPctAllowed=4.243424281672431, segmentsPerTier=35.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 907640 T1774 oass.SolrIndexSearcher.<init> Opening Searcher@6b9dfa62 main
[junit4] 2> 907654 T1743 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@d24348f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3327a424),segFN=segments_1,generation=1}
[junit4] 2> 907656 T1743 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 907657 T1743 oass.SolrIndexSearcher.<init> Opening Searcher@2cde1871 main
[junit4] 2> 907654 T1726 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@145d55f0 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@76ce51d4),segFN=segments_1,generation=1}
[junit4] 2> 907688 T1800 oasc.SolrCore.registerSearcher [solrj_collection_shard2_replica1] Registered new searcher Searcher@6b9dfa62 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 907677 T1799 oasc.SolrCore.registerSearcher [solrj_collection_shard1_replica2] Registered new searcher Searcher@2cde1871 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 907693 T1743 oasc.CoreContainer.registerCore registering core: solrj_collection_shard1_replica2
[junit4] 2> 907694 T1743 oasc.ZkController.register Register replica - core:solrj_collection_shard1_replica2 address:http://127.0.0.1:52411/gl_/ri collection:solrj_collection shard:shard1
[junit4] 2> 907688 T1774 oasc.CoreContainer.registerCore registering core: solrj_collection_shard2_replica1
[
[...truncated too long message...]
[junit4] 2> "shard":null,
[junit4] 2> "collection":"solrj_collection",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 938763 T1812 oasc.Overseer$ClusterStateUpdater.updateState shard=shard2 is already registered
[junit4] 2> 938774 T1778 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 938774 T1792 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 940262 T1706 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica1 state=down
[junit4] 2> 940268 T1706 oasc.SolrCore.close [solrj_collection_shard2_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@4d9db274
[junit4] 2> 940289 T1706 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 940290 T1706 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 940290 T1706 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 940291 T1706 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 940294 T1706 oasc.SolrCore.closeSearcher [solrj_collection_shard2_replica1] Closing main searcher on request.
[junit4] 2> 940294 T1706 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 940295 T1706 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383307946963/solrj_collection_shard2_replica1/data [CachedDir<<refCount=0;path=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383307946963/solrj_collection_shard2_replica1/data;done=false>>]
[junit4] 2> 940295 T1706 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383307946963/solrj_collection_shard2_replica1/data
[junit4] 2> 940295 T1706 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383307946963/solrj_collection_shard2_replica1/data/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383307946963/solrj_collection_shard2_replica1/data/index;done=false>>]
[junit4] 2> 940296 T1706 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383307946963/solrj_collection_shard2_replica1/data/index
[junit4] 2> 940298 T1812 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 940305 T1792 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 940311 T1792 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 940319 T1706 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/gl_/ri,null}
[junit4] 2> 940324 T1792 oasc.Overseer.start Overseer (id=90656469294186510-127.0.0.1:52420_gl_%2Fri-n_0000000004) starting
[junit4] 2> 940337 T1815 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 940340 T1814 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 940345 T1814 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 940348 T1814 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:52417/gl_/ri",
[junit4] 2> "core":"solrj_collection_shard2_replica1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52417_gl_%2Fri",
[junit4] 2> "shard":"shard2",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"solrj_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 940358 T1792 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 940376 T1706 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 52420
[junit4] 2> 940376 T1706 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=2011154278
[junit4] 2> 941381 T1814 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=90656469294186510-127.0.0.1:52420_gl_%2Fri-n_0000000004) am no longer a leader.
[junit4] 2> 941408 T1706 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/gl_/ri,null}
[junit4] 2> 941473 T1706 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4] 2> 941480 T1706 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:52402 52402
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=CollectionsAPIDistributedZkTest -Dtests.method=testDistribSearch -Dtests.seed=F6239E6FBA765C85 -Dtests.slow=true -Dtests.locale=es_GT -Dtests.timezone=IST -Dtests.file.encoding=UTF-8
[junit4] FAILURE 47.4s | CollectionsAPIDistributedZkTest.testDistribSearch <<<
[junit4] > Throwable #1: java.lang.AssertionError
[junit4] > at __randomizedtesting.SeedInfo.seed([F6239E6FBA765C85:77C51077CD293CB9]:0)
[junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testSolrJAPICalls(CollectionsAPIDistributedZkTest.java:265)
[junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:195)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
[junit4] > at java.lang.Thread.run(Thread.java:744)
[junit4] 2> 941608 T1706 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 47371 T1705 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 3 leaked thread(s).
[junit4] 2> 941804 T1778 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 942890 T1792 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> NOTE: test params are: codec=Lucene46: {}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=es_GT, timezone=IST
[junit4] 2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.7.0_45 (64-bit)/cpus=2,threads=1,free=127590496,total=286638080
[junit4] 2> NOTE: All tests run in this JVM: [PluginInfoTest, ShardRoutingTest, StatsComponentTest, TestSystemIdResolver, DistributedTermsComponentTest, TestPostingsSolrHighlighter, DistributedQueryElevationComponentTest, TestDocBasedVersionConstraints, UUIDFieldTest, DeleteInactiveReplicaTest, TestFuzzyAnalyzedSuggestions, DefaultValueUpdateProcessorTest, TestLMDirichletSimilarityFactory, ExternalFileFieldSortTest, TestRTGBase, SearchHandlerTest, IndexBasedSpellCheckerTest, TestCodecSupport, DocValuesTest, BinaryUpdateRequestHandlerTest, TestSolrXmlPersistence, TimeZoneUtilsTest, BlockDirectoryTest, TestQuerySenderNoQuery, TestFieldResource, TestCharFilters, ResponseLogComponentTest, TestRemoteStreaming, TestIBSimilarityFactory, UniqFieldsUpdateProcessorFactoryTest, TestJmxMonitoredMap, SOLR749Test, TestStressVersions, TestStressRecovery, TestHashPartitioner, TestManagedSchema, StatelessScriptUpdateProcessorFactoryTest, TestDistributedSearch, TermVectorComponentTest, RegexBoostProcessorTest, CurrencyFieldOpenExchangeTest, OpenCloseCoreStressTest, RecoveryZkTest, FileBasedSpellCheckerTest, PreAnalyzedUpdateProcessorTest, BasicFunctionalityTest, NotRequiredUniqueKeyTest, ClusterStateTest, BasicDistributedZk2Test, TestElisionMultitermQuery, PrimitiveFieldTypeTest, LegacyHTMLStripCharFilterTest, ConvertedLegacyTest, TestLuceneMatchVersion, TestAnalyzeInfixSuggestions, DeleteShardTest, TestUniqueKeyFieldResource, TestJoin, NoCacheHeaderTest, MoreLikeThisHandlerTest, TestBinaryResponseWriter, TestLFUCache, CollectionsAPIDistributedZkTest]
[junit4] Completed in 48.94s, 1 test, 1 failure <<< FAILURES!
[...truncated 820 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:428: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:408: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:39: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build.xml:189: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/common-build.xml:483: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:1263: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:906: There were test failures: 333 suites, 1469 tests, 1 failure, 40 ignored (5 assumptions)
Total time: 89 minutes 21 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-4.x-MacOSX (64bit/jdk1.7.0) - Build # 944 -
Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-MacOSX/944/
Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseSerialGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testDistribSearch
Error Message:
Stack Trace:
java.lang.AssertionError
at __randomizedtesting.SeedInfo.seed([A5E887ED7FFC2209:240E09F508A34235]:0)
at org.junit.Assert.fail(Assert.java:92)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.junit.Assert.assertTrue(Assert.java:54)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testSolrJAPICalls(CollectionsAPIDistributedZkTest.java:265)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:195)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:744)
Build Log:
[...truncated 10336 lines...]
[junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
[junit4] 2> 2058558 T4568 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /bl_/lo
[junit4] 2> 2058577 T4568 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1383284331691
[junit4] 2> 2058579 T4568 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 2058580 T4569 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 2058681 T4568 oasc.ZkTestServer.run start zk server on port:52938
[junit4] 2> 2058684 T4568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2058693 T4575 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@236b2af name:ZooKeeperConnection Watcher:127.0.0.1:52938 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2058694 T4568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2058694 T4568 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2058706 T4568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2058709 T4577 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@39f4b245 name:ZooKeeperConnection Watcher:127.0.0.1:52938/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2058710 T4568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2058710 T4568 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 2058718 T4568 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 2058729 T4568 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 2058739 T4568 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 2058747 T4568 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 2058748 T4568 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 2058762 T4568 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 2058763 T4568 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 2058778 T4568 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 2058779 T4568 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 2058788 T4568 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 2058789 T4568 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 2058798 T4568 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 2058799 T4568 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 2058808 T4568 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 2058808 T4568 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 2058817 T4568 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 2058818 T4568 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 2058828 T4568 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 2058829 T4568 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 2058838 T4568 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 2058839 T4568 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 2058848 T4568 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 2058849 T4568 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> Using new style solr.xml
[junit4] 2> 2058861 T4568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2058866 T4579 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@598dc932 name:ZooKeeperConnection Watcher:127.0.0.1:52938 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2058866 T4568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2058867 T4568 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2058876 T4568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2058882 T4581 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5945e371 name:ZooKeeperConnection Watcher:127.0.0.1:52938/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2058883 T4568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2058886 T4568 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.xml to /configs/conf2/solrconfig.xml
[junit4] 2> 2058887 T4568 oascc.SolrZkClient.makePath makePath: /configs/conf2/solrconfig.xml
[junit4] 2> 2058902 T4568 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf2/schema.xml
[junit4] 2> 2058904 T4568 oascc.SolrZkClient.makePath makePath: /configs/conf2/schema.xml
[junit4] 2> 2058913 T4568 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf2/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 2058914 T4568 oascc.SolrZkClient.makePath makePath: /configs/conf2/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 2058923 T4568 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf2/stopwords.txt
[junit4] 2> 2058924 T4568 oascc.SolrZkClient.makePath makePath: /configs/conf2/stopwords.txt
[junit4] 2> 2058933 T4568 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf2/protwords.txt
[junit4] 2> 2058934 T4568 oascc.SolrZkClient.makePath makePath: /configs/conf2/protwords.txt
[junit4] 2> 2058944 T4568 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf2/currency.xml
[junit4] 2> 2058944 T4568 oascc.SolrZkClient.makePath makePath: /configs/conf2/currency.xml
[junit4] 2> 2058953 T4568 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf2/open-exchange-rates.json
[junit4] 2> 2058954 T4568 oascc.SolrZkClient.makePath makePath: /configs/conf2/open-exchange-rates.json
[junit4] 2> 2058963 T4568 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf2/mapping-ISOLatin1Accent.txt
[junit4] 2> 2058964 T4568 oascc.SolrZkClient.makePath makePath: /configs/conf2/mapping-ISOLatin1Accent.txt
[junit4] 2> 2058973 T4568 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf2/old_synonyms.txt
[junit4] 2> 2058974 T4568 oascc.SolrZkClient.makePath makePath: /configs/conf2/old_synonyms.txt
[junit4] 2> 2058985 T4568 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf2/synonyms.txt
[junit4] 2> 2058986 T4568 oascc.SolrZkClient.makePath makePath: /configs/conf2/synonyms.txt
[junit4] 2> 2058995 T4568 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/elevate.xml to /configs/conf2/elevate.xml
[junit4] 2> 2058996 T4568 oascc.SolrZkClient.makePath makePath: /configs/conf2/elevate.xml
[junit4] 2> 2059437 T4568 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2059442 T4568 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52943
[junit4] 2> 2059445 T4568 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2059445 T4568 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2059446 T4568 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1383284332118
[junit4] 2> 2059446 T4568 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1383284332118/'
[junit4] 2> 2059486 T4568 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1383284332118/solr.xml
[junit4] 2> 2059568 T4568 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 2059569 T4568 oasc.CoreContainer.<init> New CoreContainer 1061636838
[junit4] 2> 2059569 T4568 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1383284332118/]
[junit4] 2> 2059572 T4568 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 2059572 T4568 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 2059573 T4568 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2059573 T4568 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2059574 T4568 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2059574 T4568 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2059574 T4568 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2059574 T4568 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2059575 T4568 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2059579 T4568 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2059580 T4568 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2059580 T4568 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52938/solr
[junit4] 2> 2059580 T4568 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2059582 T4568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2059587 T4592 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3fb4a83 name:ZooKeeperConnection Watcher:127.0.0.1:52938 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2059589 T4568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2059596 T4568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2059601 T4594 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d3aec3e name:ZooKeeperConnection Watcher:127.0.0.1:52938/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2059602 T4568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2059606 T4568 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2059618 T4568 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 2059636 T4568 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 2059643 T4568 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52943_bl_%2Flo
[junit4] 2> 2059646 T4568 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52943_bl_%2Flo
[junit4] 2> 2059660 T4568 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 2059677 T4568 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2059683 T4568 oasc.Overseer.start Overseer (id=90654921962291205-127.0.0.1:52943_bl_%2Flo-n_0000000000) starting
[junit4] 2> 2059693 T4568 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 2059705 T4596 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2059707 T4568 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 2059715 T4568 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 2059721 T4568 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2060528 T4595 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2060871 T4568 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1383284332118
[junit4] 2> 2061012 T4568 oasc.CorePropertiesLocator.discoverUnder Found core conf in /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1383284332118/conf/
[junit4] 2> 2061017 T4568 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 2061018 T4568 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 2061018 T4568 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2061024 T4568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2061029 T4599 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@289c1836 name:ZooKeeperConnection Watcher:127.0.0.1:52938/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2061029 T4568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2061033 T4568 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2061042 T4568 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 2061454 T4568 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2061458 T4568 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52947
[junit4] 2> 2061461 T4568 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2061462 T4568 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2061462 T4568 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1383284334154
[junit4] 2> 2061462 T4568 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1383284334154/'
[junit4] 2> 2061492 T4568 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1383284334154/solr.xml
[junit4] 2> 2061557 T4568 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 2061557 T4568 oasc.CoreContainer.<init> New CoreContainer 855138479
[junit4] 2> 2061557 T4568 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1383284334154/]
[junit4] 2> 2061559 T4568 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 2061559 T4568 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 2061559 T4568 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2061560 T4568 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2061560 T4568 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2061560 T4568 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2061561 T4568 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2061561 T4568 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2061561 T4568 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2061565 T4568 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2061566 T4568 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2061566 T4568 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52938/solr
[junit4] 2> 2061566 T4568 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2061568 T4568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2061579 T4610 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@791bf4c8 name:ZooKeeperConnection Watcher:127.0.0.1:52938 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2061581 T4568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2061590 T4568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2061597 T4612 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1922ba4 name:ZooKeeperConnection Watcher:127.0.0.1:52938/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2061598 T4568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2061619 T4568 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2062638 T4568 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52947_bl_%2Flo
[junit4] 2> 2062641 T4568 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52947_bl_%2Flo
[junit4] 2> 2062647 T4594 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2062647 T4612 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2062648 T4599 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 2062657 T4568 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1383284334154
[junit4] 2> 2062756 T4568 oasc.CorePropertiesLocator.discoverUnder Found core conf in /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1383284334154/conf/
[junit4] 2> 2062761 T4568 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 2062762 T4568 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 2062762 T4568 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2063199 T4568 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2063204 T4568 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52950
[junit4] 2> 2063206 T4568 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2063206 T4568 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2063207 T4568 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383284335881
[junit4] 2> 2063207 T4568 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383284335881/'
[junit4] 2> 2063245 T4568 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383284335881/solr.xml
[junit4] 2> 2063309 T4568 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 2063309 T4568 oasc.CoreContainer.<init> New CoreContainer 2122447481
[junit4] 2> 2063310 T4568 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383284335881/]
[junit4] 2> 2063311 T4568 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 2063311 T4568 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 2063312 T4568 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2063312 T4568 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2063312 T4568 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2063313 T4568 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2063313 T4568 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2063313 T4568 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2063314 T4568 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2063318 T4568 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2063318 T4568 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2063318 T4568 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52938/solr
[junit4] 2> 2063319 T4568 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2063320 T4568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2063325 T4624 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5c8ca115 name:ZooKeeperConnection Watcher:127.0.0.1:52938 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2063326 T4568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2063333 T4568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2063337 T4626 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@737048a2 name:ZooKeeperConnection Watcher:127.0.0.1:52938/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2063337 T4568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2063350 T4568 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2064362 T4568 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52950_bl_%2Flo
[junit4] 2> 2064366 T4568 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52950_bl_%2Flo
[junit4] 2> 2064374 T4626 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 2064375 T4594 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 2064375 T4612 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 2064376 T4599 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 2064389 T4568 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383284335881
[junit4] 2> 2064502 T4568 oasc.CorePropertiesLocator.discoverUnder Found core conf in /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383284335881/conf/
[junit4] 2> 2064508 T4568 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 2064509 T4568 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 2064510 T4568 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2064910 T4568 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2064917 T4568 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52953
[junit4] 2> 2064918 T4568 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2064919 T4568 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2064919 T4568 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383284337626
[junit4] 2> 2064919 T4568 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383284337626/'
[junit4] 2> 2064972 T4568 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383284337626/solr.xml
[junit4] 2> 2065048 T4568 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 2065048 T4568 oasc.CoreContainer.<init> New CoreContainer 699213230
[junit4] 2> 2065048 T4568 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383284337626/]
[junit4] 2> 2065051 T4568 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 2065052 T4568 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 2065052 T4568 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2065052 T4568 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2065053 T4568 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2065053 T4568 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2065053 T4568 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2065054 T4568 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2065054 T4568 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2065059 T4568 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2065060 T4568 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2065060 T4568 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52938/solr
[junit4] 2> 2065062 T4568 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2065064 T4568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2065069 T4638 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@77f58293 name:ZooKeeperConnection Watcher:127.0.0.1:52938 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2065071 T4568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2065078 T4568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2065084 T4640 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8eff879 name:ZooKeeperConnection Watcher:127.0.0.1:52938/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2065084 T4568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2065097 T4568 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2066108 T4568 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52953_bl_%2Flo
[junit4] 2> 2066110 T4568 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52953_bl_%2Flo
[junit4] 2> 2066120 T4626 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 2066121 T4599 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 2066121 T4640 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 2066121 T4612 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 2066121 T4594 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 2066138 T4568 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383284337626
[junit4] 2> 2066309 T4568 oasc.CorePropertiesLocator.discoverUnder Found core conf in /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383284337626/conf/
[junit4] 2> 2066317 T4568 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 2066318 T4568 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 2066319 T4568 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2066741 T4568 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2066747 T4568 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52956
[junit4] 2> 2066754 T4568 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2066755 T4568 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2066755 T4568 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383284339434
[junit4] 2> 2066756 T4568 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383284339434/'
[junit4] 2> 2066802 T4568 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383284339434/solr.xml
[junit4] 2> 2066918 T4568 oasc.ConfigSolrXml.<init> Config-defined core root directory:
[junit4] 2> 2066918 T4568 oasc.CoreContainer.<init> New CoreContainer 2143324831
[junit4] 2> 2066919 T4568 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383284339434/]
[junit4] 2> 2066921 T4568 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 2066921 T4568 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 2066921 T4568 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2066922 T4568 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2066922 T4568 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2066922 T4568 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2066923 T4568 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2066923 T4568 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2066923 T4568 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2066930 T4568 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2066930 T4568 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2066931 T4568 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52938/solr
[junit4] 2> 2066932 T4568 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2066934 T4568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2066939 T4652 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3f890e88 name:ZooKeeperConnection Watcher:127.0.0.1:52938 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2066940 T4568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2066949 T4568 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2066954 T4654 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7a0f0f9c name:ZooKeeperConnection Watcher:127.0.0.1:52938/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2066955 T4568 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2066970 T4568 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2067984 T4568 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52956_bl_%2Flo
[junit4] 2> 2067987 T4568 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52956_bl_%2Flo
[junit4] 2> 2067996 T4599 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 2067996 T4626 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 2067998 T4594 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 2067998 T4654 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 2067999 T4612 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 2067998 T4640 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4] 2> 2068012 T4568 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383284339434
[junit4] 2> 2068128 T4568 oasc.CorePropertiesLocator.discoverUnder Found core conf in /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383284339434/conf/
[junit4] 2> 2068134 T4568 oasc.CorePropertiesLocator.discover Found 1 core definitions
[junit4] 2> 2068135 T4568 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 2068135 T4568 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2068183 T4604 oasha.CollectionsHandler.handleCreateAction Creating Collection : numShards=2&collection.configName=conf1&name=solrj_collection&replicationFactor=2&action=CREATE&router.field=myOwnField&wt=javabin&router.name=compositeId&version=2
[junit4] 2> 2068186 T4594 oasc.DistributedQueue$LatchChildWatcher.process Watcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2068189 T4596 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000000 message:{
[junit4] 2> "operation":"createcollection",
[junit4] 2> "fromApi":"true",
[junit4] 2> "name":"solrj_collection",
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "collection.configName":"conf1",
[junit4] 2> "numShards":"2",
[junit4] 2> "router.field":"myOwnField",
[junit4] 2> "router.name":"compositeId"}
[junit4] 2> 2068189 T4596 oasc.OverseerCollectionProcessor.processMessage WARN OverseerCollectionProcessor.processMessage : createcollection , {
[junit4] 2> "operation":"createcollection",
[junit4] 2> "fromApi":"true",
[junit4] 2> "name":"solrj_collection",
[junit4] 2> "replicationFactor":"2",
[junit4] 2> "collection.configName":"conf1",
[junit4] 2> "numShards":"2",
[junit4] 2> "router.field":"myOwnField",
[junit4] 2> "router.name":"compositeId"}
[junit4] 2> 2069572 T4595 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2069573 T4595 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: solrj_collection
[junit4] 2> 2069573 T4595 oasc.Overseer$ClusterStateUpdater.createCollection Create collection solrj_collection with shards [shard1, shard2]
[junit4] 2> 2069585 T4599 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 2069585 T4654 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 2069586 T4640 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 2069585 T4594 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 2069586 T4612 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 2069586 T4626 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 2069626 T4596 oasc.OverseerCollectionProcessor.createCollection going to create cores replicas shardNames [shard1, shard2] , repFactor : 2
[junit4] 2> 2069626 T4596 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica1 as part of slice shard1 of collection solrj_collection on 127.0.0.1:52953_bl_%2Flo
[junit4] 2> 2069628 T4596 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica2 as part of slice shard1 of collection solrj_collection on 127.0.0.1:52950_bl_%2Flo
[junit4] 2> 2069629 T4596 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica1 as part of slice shard2 of collection solrj_collection on 127.0.0.1:52956_bl_%2Flo
[junit4] 2> 2069633 T4596 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica2 as part of slice shard2 of collection solrj_collection on 127.0.0.1:52943_bl_%2Flo
[junit4] 2> 2069642 T4636 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica1 state=down
[junit4] 2> 2069644 T4621 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica2 state=down
[junit4] 2> 2069645 T4646 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica1 state=down
[junit4] 2> 2069647 T4636 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 2069647 T4621 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 2069648 T4585 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica2 state=down
[junit4] 2> 2069649 T4646 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 2069650 T4585 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 2071099 T4595 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2071101 T4595 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:52953/bl_/lo",
[junit4] 2> "core":"solrj_collection_shard1_replica1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52953_bl_%2Flo",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"solrj_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 2071109 T4595 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:52950/bl_/lo",
[junit4] 2> "core":"solrj_collection_shard1_replica2",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52950_bl_%2Flo",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"solrj_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 2071117 T4595 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:52956/bl_/lo",
[junit4] 2> "core":"solrj_collection_shard2_replica1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52956_bl_%2Flo",
[junit4] 2> "shard":"shard2",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"solrj_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 2071126 T4595 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:52943/bl_/lo",
[junit4] 2> "core":"solrj_collection_shard2_replica2",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52943_bl_%2Flo",
[junit4] 2> "shard":"shard2",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"solrj_collection",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":null}
[junit4] 2> 2071134 T4599 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 2071134 T4594 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 2071135 T4654 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 2071135 T4626 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 2071135 T4612 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 2071136 T4640 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4] 2> 2071650 T4621 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica2
[junit4] 2> 2071650 T4636 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica1
[junit4] 2> 2071661 T4585 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica2
[junit4] 2> 2071662 T4646 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica1
[junit4] 2> 2071665 T4636 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica1' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383284337626/solrj_collection_shard1_replica1
[junit4] 2> 2071665 T4636 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
[junit4] 2> 2071665 T4585 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica2' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1383284332118/solrj_collection_shard2_replica2
[junit4] 2> 2071666 T4585 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
[junit4] 2> 2071667 T4646 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica1' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383284339434/solrj_collection_shard2_replica1
[junit4] 2> 2071667 T4646 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
[junit4] 2> 2071666 T4621 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica2' using instanceDir: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383284335881/solrj_collection_shard1_replica2
[junit4] 2> 2071668 T4621 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
[junit4] 2> 2071668 T4636 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:solrj_collection
[junit4] 2> 2071669 T4636 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection
[junit4] 2> 2071668 T4585 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:solrj_collection
[junit4] 2> 2071670 T4646 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:solrj_collection
[junit4] 2> 2071670 T4646 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection
[junit4] 2> 2071670 T4585 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection
[junit4] 2> 2071670 T4621 oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:solrj_collection
[junit4] 2> 2071672 T4621 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection
[junit4] 2> 2071677 T4646 oasc.ZkController.readConfigName Load collection config from:/collections/solrj_collection
[junit4] 2> 2071678 T4585 oasc.ZkController.readConfigName Load collection config from:/collections/solrj_collection
[junit4] 2> 2071678 T4636 oasc.ZkController.readConfigName Load collection config from:/collections/solrj_collection
[junit4] 2> 2071679 T4621 oasc.ZkController.readConfigName Load collection config from:/collections/solrj_collection
[junit4] 2> 2071680 T4646 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383284339434/solrj_collection_shard2_replica1/'
[junit4] 2> 2071682 T4585 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1383284332118/solrj_collection_shard2_replica2/'
[junit4] 2> 2071682 T4636 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383284337626/solrj_collection_shard1_replica1/'
[junit4] 2> 2071684 T4621 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383284335881/solrj_collection_shard1_replica2/'
[junit4] 2> 2071812 T4636 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 2071825 T4646 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 2071834 T4621 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 2071860 T4585 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 2071936 T4636 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2071948 T4636 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2071956 T4636 oass.IndexSchema.readSchema [solrj_collection_shard1_replica1] Schema name=test
[junit4] 2> 2071967 T4585 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2071978 T4646 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2071980 T4621 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2071980 T4585 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2071982 T4646 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2071987 T4621 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2071997 T4621 oass.IndexSchema.readSchema [solrj_collection_shard1_replica2] Schema name=test
[junit4] 2> 2072001 T4646 oass.IndexSchema.readSchema [solrj_collection_shard2_replica1] Schema name=test
[junit4] 2> 2072000 T4585 oass.IndexSchema.readSchema [solrj_collection_shard2_replica2] Schema name=test
[junit4] 2> 2073211 T4636 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 2073214 T4636 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 2073215 T4636 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 2073225 T4636 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 2073229 T4636 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2073241 T4585 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 2073242 T4585 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 2073242 T4585 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 2073257 T4585 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 2073261 T4585 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2073291 T4636 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2073293 T4585 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2073298 T4636 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2073298 T4585 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2073304 T4585 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2073306 T4585 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2073307 T4585 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2073307 T4585 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2073308 T4636 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2073309 T4585 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2073310 T4585 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2073310 T4585 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2073310 T4585 oasc.SolrCore.<init> [solrj_collection_shard2_replica2] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1383284332118/solrj_collection_shard2_replica2/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1383284332118/solrj_collection_shard2_replica2/data/
[junit4] 2> 2073311 T4585 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@55aeb86c
[junit4] 2> 2073330 T4585 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1383284332118/solrj_collection_shard2_replica2/data
[junit4] 2> 2073331 T4585 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1383284332118/solrj_collection_shard2_replica2/data/index/
[junit4] 2> 2073331 T4585 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica2] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1383284332118/solrj_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
[junit4] 2> 2073332 T4585 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1383284332118/solrj_collection_shard2_replica2/data/index
[junit4] 2> 2073332 T4585 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=47, maxMergeAtOnceExplicit=46, maxMergedSegmentMB=65.78125, floorSegmentMB=1.037109375, forceMergeDeletesPctAllowed=23.841908901797567, segmentsPerTier=35.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 2073333 T4585 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9f75a1b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@340a558f),segFN=segments_1,generation=1}
[junit4] 2> 2073333 T4585 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2073337 T4585 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 2073338 T4585 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 2073338 T4585 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 2073338 T4585 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 2073339 T4585 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 2073339 T4585 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 2073340 T4585 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2073340 T4585 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2073341 T4585 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2073341 T4585 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2073342 T4585 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 2073342 T4585 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 2073342 T4585 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2073343 T4585 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2073343 T4585 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 2073330 T4636 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2073346 T4636 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2073347 T4636 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2073356 T4585 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2073360 T4636 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2073361 T4636 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2073361 T4636 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2073361 T4636 oasc.SolrCore.<init> [solrj_collection_shard1_replica1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383284337626/solrj_collection_shard1_replica1/, dataDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383284337626/solrj_collection_shard1_replica1/data/
[junit4] 2> 2073362 T4636 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@55aeb86c
[junit4] 2> 2073364 T4585 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2073364 T4585 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2073365 T4636 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383284337626/solrj_collection_shard1_replica1/data
[junit4] 2> 2073365 T4636 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383284337626/solrj_collection_shard1_replica1/data/index/
[junit4] 2> 2073366 T4636 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica1] Solr index directory '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383284337626/solrj_collection_shard1_replica1/data/index' doesn't exist. Creating new index...
[junit4] 2> 2073366 T4585 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=42, maxMergeAtOnceExplicit=38, maxMergedSegmentMB=52.8857421875, floorSegmentMB=1.13671875, forceMergeDeletesPctAllowed=9.600340409046574, segmentsPerTier=33.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 2073367 T4636 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1383284337626/solrj_collection_shard1_replica1/data/index
[junit4] 2> 2073367 T4636 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=47, maxMergeAtOnceExplicit=46, maxMergedSegmentMB=65.78125, floorSegmentMB=1.037109375, forceMergeDeletesPctAllowed=23.841908901797567, segmentsPerTier=35.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 2073368 T4585 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@9f75a1b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@340a558f),segFN=segments_1,generation=1}
[junit4] 2> 2073368 T4585 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2073369 T4585 oass.SolrIndexSearcher.<init> Opening Searcher@497e88be main
[junit4] 2> 2073376 T4660 oasc.SolrCore.registerSearcher [solrj_collection_shard2_replica2] Registered new searcher Searcher@497e88be main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 2073377 T4585 oasc.CoreContainer.registerCore registering core: solrj_collection_shard2_replica2
[junit4] 2> 2073378 T4585 oasc.ZkController.register Register replica - core:solrj_collection_shard2_replica2 address:http://127.0.0.1:52943/bl_/lo collection:solrj_collection shard:shard2
[junit4] 2> 2073381 T4636 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7696588b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4de65f51),segFN=segments_1,generation=1}
[junit4] 2> 2073381 T4636 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2073404 T4636 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 2073405 T4636 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 2073405 T4636 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 2073406 T4636 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 2073406 T4636 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 2073407 T4636 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 2073407 T4636 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2073408 T4636 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2073409 T4636 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2073409 T4636 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2073410 T4636 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 2073411 T4636 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 2073412 T4636 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2073413 T4636 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2073415 T4636 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 2073412 T4585 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard2/election
[junit4] 2> 2073420 T4646 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 2073421 T4646 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 2073417 T4636 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2073420 T4621 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 2073423 T4621 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 2073424 T4621 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 2073425 T4646 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 2073429 T4636 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2073429 T4636 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2073432 T4636 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=42, maxMergeAtOnceExplicit=38, maxMergedSegmentMB=52.8857421875, floorSegmentMB=1.13671875, forceMergeDeletesPctAllowed=9.600340409046574, segmentsPerTier=33.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 2073433 T4636 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7696588b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@4de65f51),segFN=segments_1,generation=1}
[junit4] 2> 2073434 T4636 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2073434 T4636 oass.SolrIndexSearcher.<init> Opening Searcher@130659b1 main
[junit4] 2> 2073440 T4661 oasc.SolrCore.registerSearcher [solrj_collection_shard1_replica1] Registered new searcher Searcher@130659b1 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 2073441 T4636 oasc.CoreContainer.registerCore registering core: solrj_collection_shard1_replica1
[junit4] 2> 2073442 T4636 oasc.ZkController.register Register replica - core:solrj_collection_shard1_replica1 address:http://127.0.0.1:52953/bl_/lo collection:solrj_collection shard:shard1
[junit4] 2> 2073442 T4646 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 2073446 T4621 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 2073447 T4636 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard1/election
[junit4] 2> 2073453 T4646 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2073465 T4621 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2073473 T4585 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 2073482 T4636 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 2073491 T4585 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up for shard shard2: total=2 found=1 timeoutin=179998
[junit4] 2> 2073498 T4636 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=179998
[junit4] 2> 2073512 T4646 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2073518 T4621 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2073523 T4646 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2073529 T4621 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2073534 T4646 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2073535 T4621 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2073537 T4646 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2073538 T4646 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2073538 T4646 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2073537 T4621 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2073539 T4621 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2073540 T4621 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2073540 T4646 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2073542 T4646 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2073543 T4646 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2073544 T4646 oasc.SolrCore.<init> [solrj_collection_shard2_replica1] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383284339434/solrj_collection_shard2_replica1/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383284339434/solrj_collection_shard2_replica1/data/
[junit4] 2> 2073544 T4646 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@55aeb86c
[junit4] 2> 2073545 T4646 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383284339434/solrj_collection_shard2_replica1/data
[junit4] 2> 2073546 T4646 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383284339434/solrj_collection_shard2_replica1/data/index/
[junit4] 2> 2073547 T4646 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica1] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383284339434/solrj_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
[junit4] 2> 2073546 T4621 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2073548 T4621 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2073547 T4646 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383284339434/solrj_collection_shard2_replica1/data/index
[junit4] 2> 2073549 T4621 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2073550 T4646 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=47, maxMergeAtOnceExplicit=46, maxMergedSegmentMB=65.78125, floorSegmentMB=1.037109375, forceMergeDeletesPctAllowed=23.841908901797567, segmentsPerTier=35.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 2073550 T4621 oasc.SolrCore.<init> [solrj_collection_shard1_replica2] Opening new SolrCore at ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383284335881/solrj_collection_shard1_replica2/, dataDir=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383284335881/solrj_collection_shard1_replica2/data/
[junit4] 2> 2073550 T4621 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@55aeb86c
[junit4] 2> 2073551 T4646 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2a9363ed lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@ca9930e),segFN=segments_1,generation=1}
[junit4] 2> 2073551 T4646 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2073552 T4621 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383284335881/solrj_collection_shard1_replica2/data
[junit4] 2> 2073552 T4621 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383284335881/solrj_collection_shard1_replica2/data/index/
[junit4] 2> 2073552 T4621 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica2] Solr index directory './org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383284335881/solrj_collection_shard1_replica2/data/index' doesn't exist. Creating new index...
[junit4] 2> 2073553 T4621 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1383284335881/solrj_collection_shard1_replica2/data/index
[junit4] 2> 2073553 T4621 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=47, maxMergeAtOnceExplicit=46, maxMergedSegmentMB=65.78125, floorSegmentMB=1.037109375, forceMergeDeletesPctAllowed=23.841908901797567, segmentsPerTier=35.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 2073554 T4621 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@381b539e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1baf0a7a),segFN=segments_1,generation=1}
[junit4] 2> 2073554 T4621 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2073556 T4646 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 2073556 T4646 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 2073557 T4646 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 2073557 T4646 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 2073557 T4646 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 2073558 T4646 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 2073558 T4646 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2073559 T4621 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 2073559 T4646 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2073559 T4646 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2073559 T4621 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 2073560 T4646 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2073560 T4621 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 2073561 T4646 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 2073561 T4646 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 2073561 T4621 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 2073562 T4646 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2073563 T4621 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 2073563 T4646 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2073564 T4621 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 2073564 T4646 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 2073565 T4621 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2073566 T4621 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2073566 T4621 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2073566 T4646 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2073567 T4621 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2073568 T4621 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 2073568 T4621 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 2073569 T4621 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2073570 T4621 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2073570 T4621 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 2073572 T4646 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2073572 T4646 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2073573 T4646 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=42, maxMergeAtOnceExplicit=38, maxMergedSegmentMB=52.8857421875, floorSegmentMB=1.13671875, forceMergeDeletesPctAllowed=9.600340409046574, segmentsPerTier=33.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 2073573 T4621 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2073573 T4646 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2a9363ed lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@ca9930e),segFN=segments_1,generation=1}
[junit4] 2> 2073574 T4646 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2073575 T4646 oass.SolrIndexSearcher.<init> Opening Searcher@639c0067 main
[junit4] 2> 2073579 T4621 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2073579 T4621 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2073580 T4621 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=42, maxMergeAtOnceExplicit=38, maxMergedSegmentMB=52.8857421875, floorSegmentMB=1.13671875, forceMergeDeletesPctAllowed=9.600340409046574, segmentsPerTier=33.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 2073580 T4621 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@381b539e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1baf0a7a),segFN=segments_1,generation=1}
[junit4] 2> 2073580 T4646 oasc.CoreContainer.registerCore registering core: solrj_collection_shard2_replica1
[junit4] 2> 2073581 T4646 oasc.ZkController.register Register replica - core:solrj_collection_shard2_replica1 address:http://127.0.0.1:52956/bl_/lo collection:solrj_collection shard:shard2
[junit4] 2> 2073582 T4662 oasc.SolrCore.registerSearcher [solrj_collection_shard2_replica1] Registered new searcher Searcher@639c0067 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 2073582 T4621 oasc.SolrDeletionPolicy.updateC
[...truncated too long message...]
n_shard2_replica1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52956_bl_%2Flo",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"solrj_collection",
[junit4] 2> "core_node_name":"core_node3"}
[junit4] 2> 2104903 T4676 oasc.Overseer$ClusterStateUpdater.updateState shard=shard2 is already registered
[junit4] 2> 2104925 T4654 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4] 2> 2106413 T4568 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica1 state=down
[junit4] 2> 2106419 T4568 oasc.SolrCore.close [solrj_collection_shard2_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@6bbf0122
[junit4] 2> 2106437 T4568 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 2106437 T4568 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 2106439 T4568 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 2106439 T4568 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 2106442 T4568 oasc.SolrCore.closeSearcher [solrj_collection_shard2_replica1] Closing main searcher on request.
[junit4] 2> 2106442 T4568 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 2106444 T4568 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383284339434/solrj_collection_shard2_replica1/data/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383284339434/solrj_collection_shard2_replica1/data/index;done=false>>]
[junit4] 2> 2106444 T4568 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383284339434/solrj_collection_shard2_replica1/data/index
[junit4] 2> 2106444 T4568 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383284339434/solrj_collection_shard2_replica1/data [CachedDir<<refCount=0;path=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383284339434/solrj_collection_shard2_replica1/data;done=false>>]
[junit4] 2> 2106445 T4568 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1383284339434/solrj_collection_shard2_replica1/data
[junit4] 2> 2106445 T4676 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2106468 T4568 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/bl_/lo,null}
[junit4] 2> 2106533 T4568 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4] 2> 2106541 T4568 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:52938 52938
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=CollectionsAPIDistributedZkTest -Dtests.method=testDistribSearch -Dtests.seed=A5E887ED7FFC2209 -Dtests.slow=true -Dtests.locale=ca -Dtests.timezone=Europe/San_Marino -Dtests.file.encoding=US-ASCII
[junit4] FAILURE 48.1s | CollectionsAPIDistributedZkTest.testDistribSearch <<<
[junit4] > Throwable #1: java.lang.AssertionError
[junit4] > at __randomizedtesting.SeedInfo.seed([A5E887ED7FFC2209:240E09F508A34235]:0)
[junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testSolrJAPICalls(CollectionsAPIDistributedZkTest.java:265)
[junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:195)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
[junit4] > at java.lang.Thread.run(Thread.java:744)
[junit4] 2> 2106669 T4568 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 48122 T4567 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
[junit4] 2> 2107952 T4654 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> NOTE: test params are: codec=Lucene45: {}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=true,coord=no): {}, locale=ca, timezone=Europe/San_Marino
[junit4] 2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.7.0_45 (64-bit)/cpus=2,threads=1,free=57606048,total=271519744
[junit4] 2> NOTE: All tests run in this JVM: [DirectSolrConnectionTest, WordBreakSolrSpellCheckerTest, FullSolrCloudDistribCmdsTest, SortByFunctionTest, SearchHandlerTest, TestSolrXmlPersistor, HdfsUnloadDistributedZkTest, TestSolrXmlPersistence, AliasIntegrationTest, ZkCLITest, CurrencyFieldXmlFileTest, TestJoin, XsltUpdateRequestHandlerTest, TestRandomMergePolicy, TestSerializedLuceneMatchVersion, TestLFUCache, TestIBSimilarityFactory, ZkSolrClientTest, TestSystemIdResolver, SolrIndexConfigTest, OverseerCollectionProcessorTest, HardAutoCommitTest, BadIndexSchemaTest, SuggesterFSTTest, TestManagedSchema, ZkControllerTest, HdfsRecoveryZkTest, TestSolrXMLSerializer, DeleteInactiveReplicaTest, TestSchemaSimilarityResource, SpellCheckCollatorTest, TestDynamicFieldCollectionResource, TestCodecSupport, CurrencyFieldOpenExchangeTest, TestRandomDVFaceting, SolrCoreTest, SignatureUpdateProcessorFactoryTest, TestCSVLoader, TestBM25SimilarityFactory, UUIDFieldTest, TestQuerySenderNoQuery, CachingDirectoryFactoryTest, TestCoreContainer, UpdateParamsTest, TestArbitraryIndexDir, CoreAdminCreateDiscoverTest, TestStressLucene, TestLuceneMatchVersion, TestLMDirichletSimilarityFactory, QueryResultKeyTest, TestFieldTypeCollectionResource, HdfsBasicDistributedZkTest, TestQueryTypes, TestPHPSerializedResponseWriter, URLClassifyProcessorTest, TestUniqueKeyFieldResource, TestLRUCache, SolrTestCaseJ4Test, StressHdfsTest, TestSolrDeletionPolicy1, TermsComponentTest, CustomCollectionTest, UpdateRequestProcessorFactoryTest, TestReloadAndDeleteDocs, TestSolrQueryParser, TestStressUserVersions, CopyFieldTest, DocValuesMissingTest, TestSolrQueryParserResource, SuggesterTSTTest, TestGroupingSearch, TestPostingsSolrHighlighter, TestBinaryField, TestSchemaVersionResource, DocumentBuilderTest, TestCollationField, TestComponentsName, SynonymTokenizerTest, CSVRequestHandlerTest, ScriptEngineTest, TestFastLRUCache, LukeRequestHandlerTest, TestNoOpRegenerator, TestIndexingPerformance, TestDocBasedVersionConstraints, AddBlockUpdateTest, SolrIndexSplitterTest, TestValueSourceCache, TestSolrIndexConfig, TestCloudManagedSchemaAddField, OverseerTest, DistributedTermsComponentTest, TestAnalyzedSuggestions, QueryEqualityTest, TestWriterPerf, TestSort, InfoHandlerTest, FileBasedSpellCheckerTest, DisMaxRequestHandlerTest, TestHashPartitioner, AssignTest, TestQueryUtils, ExternalFileFieldSortTest, DirectUpdateHandlerOptimizeTest, DeleteReplicaTest, TestFoldingMultitermQuery, TestSolrXml, TestInfoStreamLogging, DirectSolrSpellCheckerTest, HdfsDirectoryTest, IndexSchemaRuntimeFieldTest, SolrXmlInZkTest, CoreMergeIndexesAdminHandlerTest, MultiTermTest, TestReversedWildcardFilterFactory, HdfsCollectionsAPIDistributedZkTest, LegacyHTMLStripCharFilterTest, AlternateDirectoryTest, TestMultiCoreConfBootstrap, TestPseudoReturnFields, AutoCommitTest, BasicFunctionalityTest, SoftAutoCommitTest, TestLMJelinekMercerSimilarityFactory, TestRandomFaceting, TestRemoteStreaming, RequestHandlersTest, FieldMutatingUpdateProcessorTest, TestJmxIntegration, TestRecoveryHdfs, TestCopyFieldCollectionResource, TestUpdate, TestJmxMonitoredMap, OpenCloseCoreStressTest, TestCoreDiscovery, BasicZkTest, NotRequiredUniqueKeyTest, RecoveryZkTest, NoCacheHeaderTest, TestBadConfig, SystemInfoHandlerTest, TermVectorComponentTest, TestFiltering, TestStressReorder, PluginInfoTest, TestDynamicFieldResource, TestManagedSchemaFieldResource, TestFuzzyAnalyzedSuggestions, TestOmitPositions, TestFunctionQuery, SpatialFilterTest, TestDocSet, ResourceLoaderTest, HdfsSyncSliceTest, TestSchemaResource, TestSolrJ, OutputWriterTest, TestSearchPerf, TestCharFilters, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, BasicDistributedZk2Test, UnloadDistributedZkTest, CollectionsAPIDistributedZkTest]
[junit4] Completed in 49.43s, 1 test, 1 failure <<< FAILURES!
[...truncated 501 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:428: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:408: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:39: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build.xml:189: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/common-build.xml:483: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:1263: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:906: There were test failures: 333 suites, 1469 tests, 1 failure, 40 ignored (5 assumptions)
Total time: 89 minutes 2 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure