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/08/22 23:28:51 UTC
[JENKINS] Lucene-Solr-trunk-Linux (32bit/ibm-j9-jdk7) - Build #
7125 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/7125/
Java: 32bit/ibm-j9-jdk7 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}
3 tests failed.
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.RecoveryZkTest
Error Message:
ERROR: SolrIndexSearcher opens=16 closes=15
Stack Trace:
java.lang.AssertionError: ERROR: SolrIndexSearcher opens=16 closes=15
at __randomizedtesting.SeedInfo.seed([4FA6C55C3C93477D]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.SolrTestCaseJ4.endTrackingSearchers(SolrTestCaseJ4.java:327)
at org.apache.solr.SolrTestCaseJ4.afterClass(SolrTestCaseJ4.java:133)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:88)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
at java.lang.reflect.Method.invoke(Method.java:613)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:700)
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:780)
REGRESSION: org.apache.solr.cloud.BasicDistributedZk2Test.testDistribSearch
Error Message:
Server at http://127.0.0.1:53546/np_ys/onenodecollectioncore returned non ok status:404, message:Can not find: /np_ys/onenodecollectioncore/update
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:53546/np_ys/onenodecollectioncore returned non ok status:404, message:Can not find: /np_ys/onenodecollectioncore/update
at __randomizedtesting.SeedInfo.seed([4FA6C55C3C93477D:CE404B444BCC2741]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:116)
at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:102)
at org.apache.solr.cloud.BasicDistributedZk2Test.testNodeWithoutCollectionForwarding(BasicDistributedZk2Test.java:196)
at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:88)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:88)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
at java.lang.reflect.Method.invoke(Method.java:613)
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:780)
REGRESSION: org.apache.solr.update.AutoCommitTest.testMaxTime
Error Message:
Exception during query
Stack Trace:
java.lang.RuntimeException: Exception during query
at __randomizedtesting.SeedInfo.seed([4FA6C55C3C93477D:D552B8BEA209DB41]:0)
at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:636)
at org.apache.solr.update.AutoCommitTest.testMaxTime(AutoCommitTest.java:227)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:88)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:55)
at java.lang.reflect.Method.invoke(Method.java:613)
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:780)
Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//result[@numFound=0]
xml response was: <?xml version="1.0" encoding="UTF-8"?>
<response>
<lst name="responseHeader"><int name="status">0</int><int name="QTime">1396</int></lst><result name="response" numFound="1" start="0"><doc><int name="id">529</int><int name="range_facet_si">529</int><arr name="range_facet_l"><long>529</long></arr><arr name="range_facet_sl"><long>529</long></arr><arr name="field_t"><str>what's inside?</str></arr><arr name="subject"><str>info</str></arr><int name="intDefault">42</int><date name="timestamp">2013-08-22T21:12:55.933Z</date><arr name="multiDefault"><str>muLti-Default</str></arr></doc></result>
</response>
request was:q=id:529&start=0&qt=standard&version=2.2&rows=20
at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:629)
... 41 more
Build Log:
[...truncated 9615 lines...]
[junit4] Suite: org.apache.solr.cloud.RecoveryZkTest
[junit4] 2> 53257 T180 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /papqd/c
[junit4] 2> 53265 T180 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-RecoveryZkTest-1377205559423
[junit4] 2> 53268 T180 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 53272 T181 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 53371 T180 oasc.ZkTestServer.run start zk server on port:46046
[junit4] 2> 53510 T180 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 53648 T189 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@dcc1ccb2 name:ZooKeeperConnection Watcher:127.0.0.1:46046 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 53648 T180 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 53650 T180 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 53669 T180 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 53670 T191 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3fbe198f name:ZooKeeperConnection Watcher:127.0.0.1:46046/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 53671 T180 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 53673 T180 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 53677 T180 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 53681 T180 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 53684 T180 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 53689 T180 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 53690 T180 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 53697 T180 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 53698 T180 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 53703 T180 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 53703 T180 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 53707 T180 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 53708 T180 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 53711 T180 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 53712 T180 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 53715 T180 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 53716 T180 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 53720 T180 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 53721 T180 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 53725 T180 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 53726 T180 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 53730 T180 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 53731 T180 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 53736 T180 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 53737 T180 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 53858 T180 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 53862 T180 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49819
[junit4] 2> 53863 T180 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 53864 T180 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 53865 T180 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1377205559899
[junit4] 2> 53865 T180 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1377205559899/'
[junit4] 2> 53875 T180 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1377205559899/solr.xml
[junit4] 2> 53911 T180 oasc.CoreContainer.<init> New CoreContainer 830958641
[junit4] 2> 53912 T180 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1377205559899/]
[junit4] 2> 53913 T180 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 53914 T180 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 53915 T180 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 53915 T180 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 53916 T180 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 53916 T180 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 53917 T180 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 53918 T180 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 53918 T180 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 53919 T180 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 53926 T180 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:46046/solr
[junit4] 2> 53933 T180 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 53934 T180 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 53938 T202 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2861c78f name:ZooKeeperConnection Watcher:127.0.0.1:46046 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 53939 T180 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 53942 T180 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 53951 T180 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 53954 T204 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@cbd36a0c name:ZooKeeperConnection Watcher:127.0.0.1:46046/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 53954 T180 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 53961 T180 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 53970 T180 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 53980 T180 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 53984 T180 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49819_papqd%2Fc
[junit4] 2> 53987 T180 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49819_papqd%2Fc
[junit4] 2> 53993 T180 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 54005 T180 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 54011 T180 oasc.Overseer.start Overseer (id=90256543546015747-127.0.0.1:49819_papqd%2Fc-n_0000000000) starting
[junit4] 2> 54020 T180 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 54032 T206 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 54033 T180 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 54039 T180 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 54042 T180 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 54056 T205 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 54058 T207 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 54058 T207 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 54064 T207 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 55562 T205 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 55567 T205 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "shard_state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:49819/papqd/c",
[junit4] 2> "state":"down",
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "node_name":"127.0.0.1:49819_papqd%2Fc",
[junit4] 2> "numShards":"1",
[junit4] 2> "shard_range":null,
[junit4] 2> "roles":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "shard":null,
[junit4] 2> "core":"collection1"}
[junit4] 2> 55568 T205 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 55571 T205 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 55642 T204 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> 56065 T207 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 56066 T207 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1377205559899/collection1
[junit4] 2> 56066 T207 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 56067 T207 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 56068 T207 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 56070 T207 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1377205559899/collection1/'
[junit4] 2> 56071 T207 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-controljetty-1377205559899/collection1/lib/classes/' to classloader
[junit4] 2> 56072 T207 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-controljetty-1377205559899/collection1/lib/README' to classloader
[junit4] 2> 56120 T207 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 56178 T207 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 56180 T207 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 56193 T207 oass.IndexSchema.readSchema [null] Schema name=test
[junit4] 2> 57206 T207 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 57216 T207 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 57219 T207 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 57238 T207 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 57243 T207 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 57248 T207 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 57250 T207 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 57251 T207 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 57251 T207 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 57253 T207 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 57253 T207 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 57253 T207 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 57254 T207 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1377205559899/collection1/, dataDir=./org.apache.solr.cloud.RecoveryZkTest-1377205559423/control/data/
[junit4] 2> 57254 T207 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@30a833b9
[junit4] 2> 57257 T207 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1377205559423/control/data
[junit4] 2> 57257 T207 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.RecoveryZkTest-1377205559423/control/data/index/
[junit4] 2> 57258 T207 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.RecoveryZkTest-1377205559423/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 57258 T207 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1377205559423/control/data/index
[junit4] 2> 57259 T207 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=32, maxMergeAtOnceExplicit=41, maxMergedSegmentMB=74.0205078125, floorSegmentMB=0.3291015625, forceMergeDeletesPctAllowed=27.652892537740957, segmentsPerTier=46.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.679503598944028
[junit4] 2> 57259 T207 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3549916c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bd8ad0ef),segFN=segments_1,generation=1}
[junit4] 2> 57260 T207 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 57266 T207 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 57267 T207 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 57267 T207 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 57267 T207 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 57268 T207 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 57268 T207 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 57269 T207 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 57269 T207 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 57269 T207 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 57272 T207 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 57273 T207 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 57273 T207 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 57273 T207 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 57274 T207 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 57275 T207 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 57276 T207 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 57279 T207 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 57279 T207 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 57280 T207 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=30, maxMergeAtOnceExplicit=39, maxMergedSegmentMB=60.98046875, floorSegmentMB=0.908203125, forceMergeDeletesPctAllowed=15.444092130393784, segmentsPerTier=37.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 57281 T207 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3549916c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@bd8ad0ef),segFN=segments_1,generation=1}
[junit4] 2> 57281 T207 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 57282 T207 oass.SolrIndexSearcher.<init> Opening Searcher@901f1cce main
[junit4] 2> 57290 T208 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@901f1cce main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 57295 T207 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 57295 T207 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49819/papqd/c collection:control_collection shard:shard1
[junit4] 2> 57297 T207 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 57303 T207 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 57314 T207 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 57317 T207 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 57318 T207 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 57319 T207 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49819/papqd/c/collection1/
[junit4] 2> 57319 T207 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 57319 T207 oasc.SyncStrategy.syncToMe http://127.0.0.1:49819/papqd/c/collection1/ has no replicas
[junit4] 2> 57320 T207 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49819/papqd/c/collection1/ shard1
[junit4] 2> 57320 T207 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 58652 T205 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 58661 T204 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> 58685 T207 oasc.ZkController.register We are http://127.0.0.1:49819/papqd/c/collection1/ and leader is http://127.0.0.1:49819/papqd/c/collection1/
[junit4] 2> 58686 T207 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49819/papqd/c
[junit4] 2> 58686 T207 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 58687 T207 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 58687 T207 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 58691 T207 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 58692 T180 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4] 2> 58693 T180 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 58694 T180 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 58701 T180 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4] 2> 58703 T180 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 58705 T211 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5fa58cea name:ZooKeeperConnection Watcher:127.0.0.1:46046/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 58705 T180 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 58707 T180 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 58711 T180 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 58803 T180 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 58806 T180 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:47043
[junit4] 2> 58808 T180 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 58809 T180 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 58810 T180 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.RecoveryZkTest-jetty1-1377205564869
[junit4] 2> 58811 T180 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.RecoveryZkTest-jetty1-1377205564869/'
[junit4] 2> 58825 T180 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1377205564869/solr.xml
[junit4] 2> 58870 T180 oasc.CoreContainer.<init> New CoreContainer 1069481904
[junit4] 2> 58871 T180 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.RecoveryZkTest-jetty1-1377205564869/]
[junit4] 2> 58872 T180 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 58873 T180 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 58873 T180 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 58874 T180 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 58875 T180 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 58876 T180 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 58876 T180 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 58877 T180 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 58878 T180 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 58878 T180 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 58885 T180 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:46046/solr
[junit4] 2> 58886 T180 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 58887 T180 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 58889 T222 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a467c000 name:ZooKeeperConnection Watcher:127.0.0.1:46046 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 58889 T180 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 58893 T180 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 58902 T180 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 58905 T224 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f8cb43a6 name:ZooKeeperConnection Watcher:127.0.0.1:46046/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 58905 T180 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 58914 T180 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 59920 T180 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:47043_papqd%2Fc
[junit4] 2> 59922 T180 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:47043_papqd%2Fc
[junit4] 2> 59925 T204 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4] 2> 59925 T224 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 59926 T211 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 59927 T204 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 59934 T225 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 59934 T225 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 59936 T225 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 60168 T205 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 60170 T205 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "shard_state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:49819/papqd/c",
[junit4] 2> "state":"active",
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "node_name":"127.0.0.1:49819_papqd%2Fc",
[junit4] 2> "numShards":"1",
[junit4] 2> "shard_range":null,
[junit4] 2> "roles":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"collection1"}
[junit4] 2> 60175 T205 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "shard_state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:47043/papqd/c",
[junit4] 2> "state":"down",
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "node_name":"127.0.0.1:47043_papqd%2Fc",
[junit4] 2> "numShards":"1",
[junit4] 2> "shard_range":null,
[junit4] 2> "roles":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard":null,
[junit4] 2> "core":"collection1"}
[junit4] 2> 60176 T205 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 60176 T205 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 60181 T224 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> 60181 T211 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> 60181 T204 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> 60936 T225 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 60937 T225 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.RecoveryZkTest-jetty1-1377205564869/collection1
[junit4] 2> 60937 T225 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 60939 T225 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 60940 T225 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 60941 T225 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.RecoveryZkTest-jetty1-1377205564869/collection1/'
[junit4] 2> 60942 T225 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty1-1377205564869/collection1/lib/classes/' to classloader
[junit4] 2> 60943 T225 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty1-1377205564869/collection1/lib/README' to classloader
[junit4] 2> 60995 T225 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 61034 T225 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 61037 T225 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 61044 T225 oass.IndexSchema.readSchema [null] Schema name=test
[junit4] 2> 61397 T225 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 61403 T225 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 61405 T225 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 61422 T225 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 61429 T225 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 61435 T225 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 61436 T225 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 61437 T225 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 61437 T225 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 61439 T225 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 61439 T225 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 61440 T225 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 61440 T225 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.RecoveryZkTest-jetty1-1377205564869/collection1/, dataDir=./org.apache.solr.cloud.RecoveryZkTest-1377205559423/jetty1/
[junit4] 2> 61440 T225 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@30a833b9
[junit4] 2> 61442 T225 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1377205559423/jetty1
[junit4] 2> 61442 T225 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.RecoveryZkTest-1377205559423/jetty1/index/
[junit4] 2> 61442 T225 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.RecoveryZkTest-1377205559423/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 61443 T225 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1377205559423/jetty1/index
[junit4] 2> 61443 T225 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=32, maxMergeAtOnceExplicit=41, maxMergedSegmentMB=74.0205078125, floorSegmentMB=0.3291015625, forceMergeDeletesPctAllowed=27.652892537740957, segmentsPerTier=46.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.679503598944028
[junit4] 2> 61444 T225 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@fae32714 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@30acda1c),segFN=segments_1,generation=1}
[junit4] 2> 61444 T225 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 61457 T225 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 61458 T225 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 61458 T225 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 61458 T225 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 61459 T225 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 61459 T225 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 61460 T225 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 61460 T225 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 61460 T225 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 61462 T225 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 61464 T225 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 61464 T225 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 61465 T225 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 61467 T225 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 61468 T225 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 61469 T225 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 61472 T225 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 61472 T225 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 61474 T225 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=30, maxMergeAtOnceExplicit=39, maxMergedSegmentMB=60.98046875, floorSegmentMB=0.908203125, forceMergeDeletesPctAllowed=15.444092130393784, segmentsPerTier=37.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 61475 T225 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@fae32714 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@30acda1c),segFN=segments_1,generation=1}
[junit4] 2> 61475 T225 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 61476 T225 oass.SolrIndexSearcher.<init> Opening Searcher@7865b7c8 main
[junit4] 2> 61491 T226 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7865b7c8 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 61499 T225 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 61500 T225 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:47043/papqd/c collection:collection1 shard:shard1
[junit4] 2> 61500 T225 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 61505 T225 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 61515 T225 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 61518 T225 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 61518 T225 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 61518 T225 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:47043/papqd/c/collection1/
[junit4] 2> 61519 T225 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 61519 T225 oasc.SyncStrategy.syncToMe http://127.0.0.1:47043/papqd/c/collection1/ has no replicas
[junit4] 2> 61519 T225 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:47043/papqd/c/collection1/ shard1
[junit4] 2> 61520 T225 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 61689 T205 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 61699 T211 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> 61700 T224 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> 61702 T204 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> 61728 T225 oasc.ZkController.register We are http://127.0.0.1:47043/papqd/c/collection1/ and leader is http://127.0.0.1:47043/papqd/c/collection1/
[junit4] 2> 61729 T225 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:47043/papqd/c
[junit4] 2> 61729 T225 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 61730 T225 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 61730 T225 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 61735 T225 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 61737 T180 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4] 2> 61738 T180 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 61739 T180 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 61839 T180 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 61841 T180 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:41836
[junit4] 2> 61842 T180 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 61843 T180 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 61844 T180 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1377205567904
[junit4] 2> 61844 T180 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1377205567904/'
[junit4] 2> 61854 T180 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1377205567904/solr.xml
[junit4] 2> 61896 T180 oasc.CoreContainer.<init> New CoreContainer 609724583
[junit4] 2> 61897 T180 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1377205567904/]
[junit4] 2> 61898 T180 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 61899 T180 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 61900 T180 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 61900 T180 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 61901 T180 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 61902 T180 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 61902 T180 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 61903 T180 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 61903 T180 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 61904 T180 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 61910 T180 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:46046/solr
[junit4] 2> 61910 T180 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 61911 T180 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 61914 T238 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8d9f204f name:ZooKeeperConnection Watcher:127.0.0.1:46046 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 61914 T180 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 61916 T180 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 61923 T180 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 61926 T240 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8ba9ffed name:ZooKeeperConnection Watcher:127.0.0.1:46046/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 61926 T180 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 61931 T180 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 62937 T180 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41836_papqd%2Fc
[junit4] 2> 62938 T180 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:41836_papqd%2Fc
[junit4] 2> 62941 T211 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4] 2> 62941 T204 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4] 2> 62942 T224 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 62942 T224 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4] 2> 62942 T240 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 62944 T211 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 62945 T204 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 62952 T241 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 62953 T241 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 62955 T241 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 63210 T205 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 63212 T205 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "shard_state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:47043/papqd/c",
[junit4] 2> "state":"active",
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "node_name":"127.0.0.1:47043_papqd%2Fc",
[junit4] 2> "numShards":"1",
[junit4] 2> "shard_range":null,
[junit4] 2> "roles":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"collection1"}
[junit4] 2> 63217 T205 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "shard_state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:41836/papqd/c",
[junit4] 2> "state":"down",
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node2",
[junit4] 2> "node_name":"127.0.0.1:41836_papqd%2Fc",
[junit4] 2> "numShards":"1",
[junit4] 2> "shard_range":null,
[junit4] 2> "roles":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard":null,
[junit4] 2> "core":"collection1"}
[junit4] 2> 63217 T205 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 63218 T205 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 63222 T211 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 63222 T224 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 63222 T204 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 63223 T240 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 63955 T241 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 63956 T241 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1377205567904/collection1
[junit4] 2> 63956 T241 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 63957 T241 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 63957 T241 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 63958 T241 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1377205567904/collection1/'
[junit4] 2> 63959 T241 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty2-1377205567904/collection1/lib/classes/' to classloader
[junit4] 2> 63960 T241 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty2-1377205567904/collection1/lib/README' to classloader
[junit4] 2> 64012 T241 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 64048 T241 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 64050 T241 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 64064 T241 oass.IndexSchema.readSchema [null] Schema name=test
[junit4] 2> 64486 T241 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 64495 T241 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 64506 T241 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 64523 T241 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 64530 T241 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 64538 T241 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 64540 T241 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 64540 T241 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 64541 T241 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 64543 T241 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 64543 T241 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 64545 T241 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 64545 T241 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1377205567904/collection1/, dataDir=./org.apache.solr.cloud.RecoveryZkTest-1377205559423/jetty2/
[junit4] 2> 64546 T241 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@30a833b9
[junit4] 2> 64548 T241 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1377205559423/jetty2
[junit4] 2> 64548 T241 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.RecoveryZkTest-1377205559423/jetty2/index/
[junit4] 2> 64549 T241 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.RecoveryZkTest-1377205559423/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 64550 T241 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1377205559423/jetty2/index
[junit4] 2> 64552 T241 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=32, maxMergeAtOnceExplicit=41, maxMergedSegmentMB=74.0205078125, floorSegmentMB=0.3291015625, forceMergeDeletesPctAllowed=27.652892537740957, segmentsPerTier=46.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.679503598944028
[junit4] 2> 64553 T241 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@62f3a9d1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@f6820c62),segFN=segments_1,generation=1}
[junit4] 2> 64554 T241 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 64567 T241 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 64567 T241 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 64568 T241 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 64568 T241 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 64569 T241 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 64570 T241 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 64570 T241 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 64571 T241 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 64572 T241 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 64574 T241 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 64576 T241 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 64576 T241 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 64577 T241 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 64579 T241 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 64580 T241 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 64582 T241 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 64586 T241 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 64587 T241 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 64589 T241 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=30, maxMergeAtOnceExplicit=39, maxMergedSegmentMB=60.98046875, floorSegmentMB=0.908203125, forceMergeDeletesPctAllowed=15.444092130393784, segmentsPerTier=37.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 64590 T241 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@62f3a9d1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@f6820c62),segFN=segments_1,generation=1}
[junit4] 2> 64591 T241 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 64591 T241 oass.SolrIndexSearcher.<init> Opening Searcher@8369a9fc main
[junit4] 2> 64604 T242 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@8369a9fc main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 64612 T241 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 64613 T241 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:41836/papqd/c collection:collection1 shard:shard1
[junit4] 2> 64613 T241 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 64624 T241 oasc.ZkController.register We are http://127.0.0.1:41836/papqd/c/collection1/ and leader is http://127.0.0.1:47043/papqd/c/collection1/
[junit4] 2> 64625 T241 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:41836/papqd/c
[junit4] 2> 64625 T241 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 64626 T241 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C129 name=collection1 org.apache.solr.core.SolrCore@adfab8c6 url=http://127.0.0.1:41836/papqd/c/collection1 node=127.0.0.1:41836_papqd%2Fc C129_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:41836/papqd/c, state=down, node_name=127.0.0.1:41836_papqd%2Fc, core=collection1}
[junit4] 2> 64630 T243 C129 P41836 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 64631 T243 C129 P41836 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 64631 T243 C129 P41836 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4] 2> 64631 T241 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 64631 T243 C129 P41836 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 64634 T180 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
[junit4] 2> 64635 T180 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 64634 T243 C129 P41836 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 64636 T180 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 64647 T180 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 64655 T220 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true
[junit4] 2> ASYNC NEW_CORE C130 name=collection1 org.apache.solr.core.SolrCore@6025f49 url=http://127.0.0.1:49819/papqd/c/collection1 node=127.0.0.1:49819_papqd%2Fc C130_STATE=coll:control_collection core:collection1 props:{base_url=http://127.0.0.1:49819/papqd/c, state=active, node_name=127.0.0.1:49819_papqd%2Fc, core=collection1, leader=true}
[junit4] 2> 64674 T197 C130 P49819 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {add=[10001 (1444104708636540928)]} 0 8
[junit4] 2> 64674 T198 C130 P49819 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {add=[1 (1444104708636540929)]} 0 8
[junit4] 2> ASYNC NEW_CORE C131 name=collection1 org.apache.solr.core.SolrCore@4d129097 url=http://127.0.0.1:47043/papqd/c/collection1 node=127.0.0.1:47043_papqd%2Fc C131_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:47043/papqd/c, state=active, node_name=127.0.0.1:47043_papqd%2Fc, core=collection1, leader=true}
[junit4] 2> 64694 T219 C131 P47043 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {add=[10001 (1444104708658561024)]} 0 2
[junit4] 2> 64694 T217 C131 P47043 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {add=[1 (1444104708658561025)]} 0 2
[junit4] 2> 64732 T205 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 64733 T205 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "shard_state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:41836/papqd/c",
[junit4] 2> "state":"recovering",
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node2",
[junit4] 2> "node_name":"127.0.0.1:41836_papqd%2Fc",
[junit4] 2> "numShards":"1",
[junit4] 2> "shard_range":null,
[junit4] 2> "roles":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "core":"collection1"}
[junit4] 2> 64740 T211 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 64741 T204 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 64741 T224 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 64741 T240 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 64747 T200 C130 P49819 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {add=[10002 (1444104708715184128)]} 0 1
[junit4] 2> 64748 T197 C130 P49819 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {add=[2 (1444104708715184129)]} 0 2
[junit4] 2> C129_STATE=coll:collection1 core:collection1 props:{base_url=http://127.0.0.1:41836/papqd/c, state=recovering, node_name=127.0.0.1:41836_papqd%2Fc, core=collection1}
[junit4] 2> 64765 T235 C129 P41836 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:47043/papqd/c/collection1/&version=2&wt=javabin} {add=[10002 (1444104708721475584)]} 0 2
[junit4] 2> 64767 T218 C131 P47043 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {add=[10002 (1444104708721475584)]} 0 16
[junit4] 2> 64769 T233 C129 P41836 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:47043/papqd/c/collection1/&version=2&wt=javabin} {add=[2 (1444104708721475585)]} 0 1
[junit4] 2> 64771 T219 C131 P47043 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {add=[2 (1444104708721475585)]} 0 20
[junit4] 2> 64820 T198 C130 P49819 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {add=[10003 (1444104708791730176)]} 0 1
[junit4] 2> 64825 T199 C130 P49819 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {add=[3 (1444104708795924480)]} 0 2
[junit4] 2> 64829 T234 C129 P41836 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:47043/papqd/c/collection1/&version=2&wt=javabin} {add=[10003 (1444104708796973056)]} 0 2
[junit4] 2> 64831 T217 C131 P47043 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {add=[10003 (1444104708796973056)]} 0 7
[junit4] 2> 64834 T236 C129 P41836 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:47043/papqd/c/collection1/&version=2&wt=javabin} {add=[3 (1444104708801167360)]} 0 2
[junit4] 2> 64836 T219 C131 P47043 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {add=[3 (1444104708801167360)]} 0 8
[junit4] 2> 64852 T180 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 41836
[junit4] 2> 64853 T180 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=609724583
[junit4] 2> 64996 T200 C130 P49819 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {delete=[10001 (-1444104708977328128)]} 0 1
[junit4] 2> 64996 T197 C130 P49819 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {delete=[1 (-1444104708977328129)]} 0 0
[junit4] 2> 65003 T235 C129 P41836 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:47043/papqd/c/collection1/&version=2&wt=javabin} {delete=[10001 (-1444104708980473856)]} 0 1
[junit4] 2> 65004 T233 C129 P41836 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:47043/papqd/c/collection1/&version=2&wt=javabin} {delete=[1 (-1444104708982571008)]} 0 1
[junit4] 2> 65005 T217 C131 P47043 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {delete=[1 (-1444104708982571008)]} 0 4
[junit4] 2> 65006 T218 C131 P47043 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {delete=[10001 (-1444104708980473856)]} 0 7
[junit4] 2> 65010 T198 C130 P49819 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {add=[4 (1444104708990959616)]} 0 2
[junit4] 2> 65010 T199 C130 P49819 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {add=[10004 (1444104708990959617)]} 0 1
[junit4] 2> 65018 T234 C129 P41836 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:47043/papqd/c/collection1/&version=2&wt=javabin} {add=[4 (1444104708995153920)]} 0 2
[junit4] 2> 65019 T236 C129 P41836 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:47043/papqd/c/collection1/&version=2&wt=javabin} {add=[10004 (1444104708995153921)]} 0 2
[junit4] 2> 65019 T219 C131 P47043 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {add=[4 (1444104708995153920)]} 0 6
[junit4] 2> 65020 T217 C131 P47043 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {add=[10004 (1444104708995153921)]} 0 7
[junit4] 2> 65073 T200 C130 P49819 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {delete=[2 (-1444104709057019904)]} 0 1
[junit4] 2> 65073 T197 C130 P49819 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {delete=[10002 (-1444104709058068480)]} 0 0
[junit4] 2> 65080 T233 C129 P41836 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:47043/papqd/c/collection1/&version=2&wt=javabin} {delete=[2 (-1444104709062262784)]} 0 1
[junit4] 2> 65080 T234 C129 P41836 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:47043/papqd/c/collection1/&version=2&wt=javabin} {delete=[10002 (-1444104709062262785)]} 0 0
[junit4] 2> 65081 T218 C131 P47043 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {delete=[2 (-1444104709062262784)]} 0 4
[junit4] 2> 65082 T219 C131 P47043 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {delete=[10002 (-1444104709062262785)]} 0 5
[junit4] 2> 65086 T199 C130 P49819 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {add=[5 (1444104709070651392)]} 0 1
[junit4] 2> 65088 T198 C130 P49819 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {add=[10005 (1444104709072748544)]} 0 2
[junit4] 2> 65094 T235 C129 P41836 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:47043/papqd/c/collection1/&version=2&wt=javabin} {add=[5 (1444104709074845696)]} 0 1
[junit4] 2> 65095 T236 C129 P41836 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:47043/papqd/c/collection1/&version=2&wt=javabin} {add=[10005 (1444104709076942848)]} 0 1
[junit4] 2> 65096 T217 C131 P47043 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {add=[5 (1444104709074845696)]} 0 7
[junit4] 2> 65096 T218 C131 P47043 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {add=[10005 (1444104709076942848)]} 0 5
[junit4] 2> 65137 T197 C130 P49819 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {add=[6 (1444104709124128768)]} 0 1
[junit4] 2> 65138 T200 C130 P49819 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {add=[10006 (1444104709125177344)]} 0 1
[junit4] 2> 65146 T233 C129 P41836 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:47043/papqd/c/collection1/&version=2&wt=javabin} {add=[6 (1444104709129371648)]} 0 1
[junit4] 2> 65147 T234 C129 P41836 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:47043/papqd/c/collection1/&version=2&wt=javabin} {add=[10006 (1444104709130420224)]} 0 1
[junit4] 2> 65147 T219 C131 P47043 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {add=[6 (1444104709129371648)]} 0 6
[junit4] 2> 65149 T217 C131 P47043 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {add=[10006 (1444104709130420224)]} 0 7
[junit4] 2> 65216 T199 C130 P49819 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {add=[7 (1444104709206966272)]} 0 2
[junit4] 2> 65217 T197 C130 P49819 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {add=[10007 (1444104709208014848)]} 0 1
[junit4] 2> 65225 T235 C129 P41836 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:47043/papqd/c/collection1/&version=2&wt=javabin} {add=[7 (1444104709212209152)]} 0 1
[junit4] 2> 65226 T218 C131 P47043 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {add=[7 (1444104709212209152)]} 0 7
[junit4] 2> 65227 T236 C129 P41836 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:47043/papqd/c/collection1/&version=2&wt=javabin} {add=[10007 (1444104709214306304)]} 0 1
[junit4] 2> 65228 T219 C131 P47043 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {add=[10007 (1444104709214306304)]} 0 6
[junit4] 2> 65289 T200 C130 P49819 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {add=[8 (1444104709283512320)]} 0 1
[junit4] 2> 65291 T198 C130 P49819 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {add=[10008 (1444104709285609472)]} 0 2
[junit4] 2> 65297 T233 C129 P41836 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:47043/papqd/c/collection1/&version=2&wt=javabin} {add=[8 (1444104709288755200)]} 0 1
[junit4] 2> 65298 T218 C131 P47043 oasup.LogUpdateProcessor.finish [collection1] webapp=/papqd/c path=/update params={version=2&wt=javabin} {add=[8 (1444104709288755200)]} 0 5
[junit
[...truncated too long message...]
odecollection/leader_elect/shard1 (1)
[junit4] 1> /solr/collections/onenodecollection/leader_elect/shard1/election (1)
[junit4] 1> /solr/collections/onenodecollection/leader_elect/shard1/election/90256585909010438-core_node1-n_0000000000 (0)
[junit4] 1> /solr/collections/onenodecollection/leaders (1)
[junit4] 1> /solr/collections/onenodecollection/leaders/shard1 (0)
[junit4] 1> DATA:
[junit4] 1> {
[junit4] 1> "base_url":"http://127.0.0.1:57668/np_ys",
[junit4] 1> "node_name":"127.0.0.1:57668_np_ys",
[junit4] 1> "core":"onenodecollectioncore"}
[junit4] 1> /solr/aliases.json (0)
[junit4] 1> /solr/live_nodes (5)
[junit4] 1> /solr/live_nodes/127.0.0.1:34029_np_ys (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:57668_np_ys (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:38850_np_ys (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:53546_np_ys (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:35185_np_ys (0)
[junit4] 1> /solr/clusterstate.json (0)
[junit4] 1> DATA:
[junit4] 1> {
[junit4] 1> "control_collection":{
[junit4] 1> "shards":{"shard1":{
[junit4] 1> "range":"80000000-7fffffff",
[junit4] 1> "state":"active",
[junit4] 1> "replicas":{"core_node1":{
[junit4] 1> "base_url":"http://127.0.0.1:38850/np_ys",
[junit4] 1> "state":"active",
[junit4] 1> "node_name":"127.0.0.1:38850_np_ys",
[junit4] 1> "core":"collection1",
[junit4] 1> "leader":"true"}}}},
[junit4] 1> "maxShardsPerNode":"1",
[junit4] 1> "router":"compositeId",
[junit4] 1> "replicationFactor":"1"},
[junit4] 1> "onenodecollection":{
[junit4] 1> "shards":{"shard1":{
[junit4] 1> "range":"80000000-7fffffff",
[junit4] 1> "state":"active",
[junit4] 1> "replicas":{"core_node1":{
[junit4] 1> "base_url":"http://127.0.0.1:57668/np_ys",
[junit4] 1> "state":"active",
[junit4] 1> "node_name":"127.0.0.1:57668_np_ys",
[junit4] 1> "roles":"none",
[junit4] 1> "core":"onenodecollectioncore",
[junit4] 1> "leader":"true"}}}},
[junit4] 1> "maxShardsPerNode":"1",
[junit4] 1> "router":"compositeId",
[junit4] 1> "replicationFactor":"1"},
[junit4] 1> "collection1":{
[junit4] 1> "shards":{
[junit4] 1> "shard1":{
[junit4] 1> "range":"80000000-ffffffff",
[junit4] 1> "state":"active",
[junit4] 1> "replicas":{
[junit4] 1> "core_node1":{
[junit4] 1> "base_url":"http://127.0.0.1:57668/np_ys",
[junit4] 1> "state":"active",
[junit4] 1> "node_name":"127.0.0.1:57668_np_ys",
[junit4] 1> "core":"collection1",
[junit4] 1> "leader":"true"},
[junit4] 1> "core_node3":{
[junit4] 1> "base_url":"http://127.0.0.1:35185/np_ys",
[junit4] 1> "state":"active",
[junit4] 1> "node_name":"127.0.0.1:35185_np_ys",
[junit4] 1> "core":"collection1"}}},
[junit4] 1> "shard2":{
[junit4] 1> "range":"0-7fffffff",
[junit4] 1> "state":"active",
[junit4] 1> "replicas":{
[junit4] 1> "core_node2":{
[junit4] 1> "base_url":"http://127.0.0.1:53546/np_ys",
[junit4] 1> "state":"active",
[junit4] 1> "node_name":"127.0.0.1:53546_np_ys",
[junit4] 1> "core":"collection1",
[junit4] 1> "leader":"true"},
[junit4] 1> "core_node4":{
[junit4] 1> "base_url":"http://127.0.0.1:34029/np_ys",
[junit4] 1> "state":"active",
[junit4] 1> "node_name":"127.0.0.1:34029_np_ys",
[junit4] 1> "core":"collection1"}}}},
[junit4] 1> "maxShardsPerNode":"1",
[junit4] 1> "router":"compositeId",
[junit4] 1> "replicationFactor":"1"}}
[junit4] 1> /zookeeper (1)
[junit4] 1> DATA:
[junit4] 1>
[junit4] 1>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=BasicDistributedZk2Test -Dtests.method=testDistribSearch -Dtests.seed=4FA6C55C3C93477D -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=el_CY -Dtests.timezone=Africa/Bamako -Dtests.file.encoding=UTF-8
[junit4] ERROR 30.5s J1 | BasicDistributedZk2Test.testDistribSearch <<<
[junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:53546/np_ys/onenodecollectioncore returned non ok status:404, message:Can not find: /np_ys/onenodecollectioncore/update
[junit4] > at __randomizedtesting.SeedInfo.seed([4FA6C55C3C93477D:CE404B444BCC2741]:0)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
[junit4] > at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:117)
[junit4] > at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:116)
[junit4] > at org.apache.solr.client.solrj.SolrServer.add(SolrServer.java:102)
[junit4] > at org.apache.solr.cloud.BasicDistributedZk2Test.testNodeWithoutCollectionForwarding(BasicDistributedZk2Test.java:196)
[junit4] > at org.apache.solr.cloud.BasicDistributedZk2Test.doTest(BasicDistributedZk2Test.java:88)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
[junit4] > at java.lang.Thread.run(Thread.java:780)
[junit4] 2> 730289 T1810 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 30536 T1809 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting, sim=DefaultSimilarity, locale=el_CY, timezone=Africa/Bamako
[junit4] 2> NOTE: Linux 3.2.0-52-generic x86/IBM Corporation 1.7.0 (32-bit)/cpus=8,threads=3,free=47943504,total=173670400
[junit4] 2> NOTE: All tests run in this JVM: [TestRecovery, ZkSolrClientTest, TestIndexSearcher, TestDynamicFieldCollectionResource, SimplePostToolTest, TestDefaultSearchFieldResource, TestHashPartitioner, TestSolrJ, TimeZoneUtilsTest, TestArbitraryIndexDir, CachingDirectoryFactoryTest, TestDFRSimilarityFactory, BasicZkTest, TestCodecSupport, DocValuesMultiTest, SolrPluginUtilsTest, TestFiltering, TestJmxIntegration, ZkNodePropsTest, DeleteShardTest, TestDistributedSearch, TestSolrQueryParserDefaultOperatorResource, TestSolrDeletionPolicy2, DateFieldTest, TestSolrXml, TestFieldResource, TestZkChroot, SolrTestCaseJ4Test, TestSolr4Spatial, HighlighterTest, TestFuzzyAnalyzedSuggestions, SpellCheckCollatorTest, TestSolrCoreProperties, XmlUpdateRequestHandlerTest, BadCopyFieldTest, LeaderElectionIntegrationTest, PrimUtilsTest, SpellCheckComponentTest, TestStressRecovery, TestCloudManagedSchemaAddField, UniqFieldsUpdateProcessorFactoryTest, TestStressReorder, TestRecoveryHdfs, TestDefaultSimilarityFactory, ConvertedLegacyTest, TestFoldingMultitermQuery, HdfsSyncSliceTest, TestPartialUpdateDeduplication, TestFastLRUCache, DebugComponentTest, StandardRequestHandlerTest, CoreContainerCoreInitFailuresTest, CurrencyFieldOpenExchangeTest, DirectUpdateHandlerTest, RequestHandlersTest, NoCacheHeaderTest, TestCopyFieldCollectionResource, TestQuerySenderNoQuery, TestUpdate, TestAddFieldRealTimeGet, MinimalSchemaTest, TestManagedSchemaFieldResource, JSONWriterTest, TestBinaryResponseWriter, TestFieldTypeResource, TestRTGBase, HighlighterConfigTest, MultiTermTest, TestQuerySenderListener, IndexSchemaRuntimeFieldTest, TestRangeQuery, TestDistributedGrouping, TestNumberUtils, TestQueryTypes, DirectSolrSpellCheckerTest, PingRequestHandlerTest, ChaosMonkeySafeLeaderTest, BasicDistributedZk2Test]
[junit4] Completed on J1 in 31.31s, 1 test, 1 error <<< FAILURES!
[...truncated 550 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:389: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:382: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:181: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:450: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1230: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:873: There were test failures: 323 suites, 1403 tests, 1 suite-level error, 2 errors, 35 ignored (6 assumptions)
Total time: 44 minutes 54 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/ibm-j9-jdk7 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure